Release 1.17.14

- [FEATURE] http_client can now collect stats: time to connect, TTFB,
  time to download, requests per seconds, and bandwidth.  See -t flag.

- [BUGFIX] http_client: -B, -K, and -r can be used at the same time.

- [BUGFIX] http_client: do not display cert chain before each request.
  Now this is only done once per connection, if the handshake is
  successful and -a option is given.

- [BUGFIX] Do not wait to dispatch on_close() after reading.  If a
  stream is scheduled to be closed after on_read() callback returns,
  close it immediately instead of waiting until the end of the tick.
  If client creates new request from on_close() event, they will be
  processed in the same tick instead of waiting for the next one.

- [BUGFIX] HEADERS stream is critical: always treat it with highest
  priority.

CHANGELOG

@@ -1,3 +1,19 @@
+2019-01-16
+    - 1.17.14
+    - [FEATURE] http_client can now collect stats: time to connect, TTFB,
+      time to download, requests per seconds, and bandwidth.  See -t flag.
+    - [BUGFIX] http_client: -B, -K, and -r can be used at the same time.
+    - [BUGFIX] http_client: do not display cert chain before each request.
+      Now this is only done once per connection, if the handshake is
+      successful and -a option is given.
+    - [BUGFIX] Do not wait to dispatch on_close() after reading.  If a
+      stream is scheduled to be closed after on_read() callback returns,
+      close it immediately instead of waiting until the end of the tick.
+      If client creates new request from on_close() event, they will be
+      processed in the same tick instead of waiting for the next one.
+    - [BUGFIX] HEADERS stream is critical: always treat it with highest
+      priority.
+
 2019-01-10
     - 1.17.12
     - [FEATURE] http_client can now issue parallel requests in the context

EXAMPLES.txt

@@ -119,15 +119,15 @@ Control Network-Related Stuff
 More Compilation Options
 ------------------------
 
--DFULL_CONN_STATS=1
+-DLSQUIC_CONN_STATS=1
 
-    Track some statistics about full connection -- packets in, sent, delayed,
+    Track some statistics about connections -- packets in, sent, delayed,
     stream payload per packet size ratio, and some others -- and print them
     at NOTICE level when connection is destroyed.
 
-    This is useful when performing network testing and especially analyzing
+    Cumulative connections statistics are printed by the engine when it is
-    the effects of changing send buffer size (see -S sndbuf= in the previous
+    destroyed if lsquic_engine_api.ea_stats_fh is set.  The HTTP client
-    section).
+    programs sets it when -t or -T command-line option is used.
 
 -DLSQUIC_PACKINTS_SANITY_CHECK=1
 

include/lsquic.h

@@ -25,7 +25,7 @@ extern "C" {
 
 #define LSQUIC_MAJOR_VERSION 1
 #define LSQUIC_MINOR_VERSION 17
-#define LSQUIC_PATCH_VERSION 12
+#define LSQUIC_PATCH_VERSION 14
 
 /**
  * Engine flags:
@@ -614,6 +614,13 @@ typedef struct lsquic_engine_api
      */
     const struct lsquic_hset_if         *ea_hsi_if;
     void                                *ea_hsi_ctx;
+#if LSQUIC_CONN_STATS
+    /**
+     * If set, engine will print cumulative connection statistics to this
+     * file just before it is destroyed.
+     */
+    void /* FILE, really */             *ea_stats_fh;
+#endif
 } lsquic_engine_api_t;
 
 /**

src/liblsquic/lsquic_conn.h

@@ -22,6 +22,9 @@ struct lsquic_packet_in;
 struct sockaddr;
 struct parse_funcs;
 struct attq_elem;
+#if LSQUIC_CONN_STATS
+struct conn_stats;
+#endif
 
 enum lsquic_conn_flags {
     LSCONN_TICKED         = (1 << 0),
@@ -83,6 +86,11 @@ struct conn_iface
 
     lsquic_time_t
     (*ci_next_tick_time) (struct lsquic_conn *);
+
+#if LSQUIC_CONN_STATS
+    const struct conn_stats *
+    (*ci_get_stats) (struct lsquic_conn *);
+#endif
 };
 
 struct lsquic_conn
@@ -127,4 +135,37 @@ lsquic_conn_copy_and_release_pi_data (const lsquic_conn_t *conn,
 
 #define lsquic_conn_adv_time(c) ((c)->cn_attq_elem->ae_adv_time)
 
+#if LSQUIC_CONN_STATS
+struct conn_stats {
+    /* All counters are of the same type, unsigned long, because we cast the
+     * struct to an array to update the aggregate.
+     */
+    unsigned long           n_ticks;            /* How many time connection was ticked */
+    struct {
+        unsigned long       stream_data_sz;     /* Sum of all STREAM frames payload */
+        unsigned long       stream_frames;      /* Number of STREAM frames */
+        unsigned long       packets,            /* Incoming packets */
+                            undec_packets,      /* Undecryptable packets */
+                            dup_packets,        /* Duplicate packets */
+                            err_packets;        /* Error packets(?) */
+        unsigned long       n_acks,
+                            n_acks_proc,
+                            n_acks_merged[2];
+        unsigned long       bytes;              /* Overall bytes in */
+        unsigned long       headers_uncomp;     /* Sum of uncompressed header bytes */
+        unsigned long       headers_comp;       /* Sum of compressed header bytes */
+    }                   in;
+    struct {
+        unsigned long       stream_data_sz;
+        unsigned long       stream_frames;
+        unsigned long       acks;
+        unsigned long       packets;            /* Number of sent packets */
+        unsigned long       retx_packets;       /* Number of retransmitted packets */
+        unsigned long       bytes;              /* Overall bytes out */
+        unsigned long       headers_uncomp;     /* Sum of uncompressed header bytes */
+        unsigned long       headers_comp;       /* Sum of compressed header bytes */
+    }                   out;
+};
+#endif
+
 #endif

src/liblsquic/lsquic_conn_public.h

@@ -16,6 +16,9 @@ struct lsquic_mm;
 struct lsquic_hash;
 struct headers_stream;
 struct lsquic_send_ctl;
+#if LSQUIC_CONN_STATS
+struct conn_stats;
+#endif
 
 struct lsquic_conn_public {
     struct lsquic_streams_tailq     sending_streams,    /* Send RST_STREAM, BLOCKED, and WUF frames */
@@ -32,6 +35,9 @@ struct lsquic_conn_public {
     struct lsquic_mm               *mm;
     struct headers_stream          *hs;
     struct lsquic_send_ctl         *send_ctl;
+#if LSQUIC_CONN_STATS
+    struct conn_stats              *conn_stats;
+#endif
 };
 
 #endif

src/liblsquic/lsquic_engine.c

@@ -171,6 +171,13 @@ struct lsquic_engine
     unsigned                           n_conns;
     lsquic_time_t                      deadline;
     lsquic_time_t                      resume_sending_at;
+#if LSQUIC_CONN_STATS
+    struct {
+        unsigned                conns;
+    }                                  stats;
+    struct conn_stats                  conn_stats_sum;
+    FILE                              *stats_fh;
+#endif
     struct out_batch                   out_batch;
 };
 
@@ -348,6 +355,9 @@ lsquic_engine_new (unsigned flags,
     eng_hist_init(&engine->history);
     engine->batch_size = INITIAL_OUT_BATCH_SIZE;
 
+#if LSQUIC_CONN_STATS
+    engine->stats_fh = api->ea_stats_fh;
+#endif
 
     LSQ_INFO("instantiated engine");
     return engine;
@@ -368,12 +378,37 @@ shrink_batch_size (struct lsquic_engine *engine)
 }
 
 
+#if LSQUIC_CONN_STATS
+void
+update_stats_sum (struct lsquic_engine *engine, struct lsquic_conn *conn)
+{
+    unsigned long *const dst = (unsigned long *) &engine->conn_stats_sum;
+    const unsigned long *src;
+    const struct conn_stats *stats;
+    unsigned i;
+
+    if (conn->cn_if->ci_get_stats && (stats = conn->cn_if->ci_get_stats(conn)))
+    {
+        ++engine->stats.conns;
+        src = (unsigned long *) stats;
+        for (i = 0; i < sizeof(*stats) / sizeof(unsigned long); ++i)
+            dst[i] += src[i];
+    }
+}
+
+
+#endif
+
+
 /* Wrapper to make sure important things occur before the connection is
  * really destroyed.
  */
 static void
 destroy_conn (struct lsquic_engine *engine, lsquic_conn_t *conn)
 {
+#if LSQUIC_CONN_STATS
+    update_stats_sum(engine, conn);
+#endif
     --engine->n_conns;
     conn->cn_flags |= LSCONN_NEVER_TICKABLE;
     conn->cn_if->ci_destroy(conn);
@@ -580,6 +615,44 @@ lsquic_engine_destroy (lsquic_engine_t *engine)
     assert(0 == lsquic_mh_count(&engine->conns_tickable));
     lsquic_mm_cleanup(&engine->pub.enp_mm);
     free(engine->conns_tickable.mh_elems);
+#if LSQUIC_CONN_STATS
+    if (engine->stats_fh)
+    {
+        const struct conn_stats *const stats = &engine->conn_stats_sum;
+        fprintf(engine->stats_fh, "Aggregate connection stats collected by engine:\n");
+        fprintf(engine->stats_fh, "Connections: %u\n", engine->stats.conns);
+        fprintf(engine->stats_fh, "Ticks: %lu\n", stats->n_ticks);
+        fprintf(engine->stats_fh, "In:\n");
+        fprintf(engine->stats_fh, "    Total bytes: %lu\n", stats->in.bytes);
+        fprintf(engine->stats_fh, "    packets: %lu\n", stats->in.packets);
+        fprintf(engine->stats_fh, "    undecryptable packets: %lu\n", stats->in.undec_packets);
+        fprintf(engine->stats_fh, "    duplicate packets: %lu\n", stats->in.dup_packets);
+        fprintf(engine->stats_fh, "    error packets: %lu\n", stats->in.err_packets);
+        fprintf(engine->stats_fh, "    STREAM frame count: %lu\n", stats->in.stream_frames);
+        fprintf(engine->stats_fh, "    STREAM payload size: %lu\n", stats->in.stream_data_sz);
+        fprintf(engine->stats_fh, "    Header bytes: %lu; uncompressed: %lu; ratio %.3lf\n",
+            stats->in.headers_comp, stats->in.headers_uncomp,
+            stats->in.headers_uncomp ?
+            (double) stats->in.headers_comp / (double) stats->in.headers_uncomp
+            : 0);
+        fprintf(engine->stats_fh, "    ACK frames: %lu\n", stats->in.n_acks);
+        fprintf(engine->stats_fh, "    ACK frames processed: %lu\n", stats->in.n_acks_proc);
+        fprintf(engine->stats_fh, "    ACK frames merged to new: %lu\n", stats->in.n_acks_merged[0]);
+        fprintf(engine->stats_fh, "    ACK frames merged to old: %lu\n", stats->in.n_acks_merged[1]);
+        fprintf(engine->stats_fh, "Out:\n");
+        fprintf(engine->stats_fh, "    Total bytes: %lu\n", stats->out.bytes);
+        fprintf(engine->stats_fh, "    packets: %lu\n", stats->out.packets);
+        fprintf(engine->stats_fh, "    retx packets: %lu\n", stats->out.retx_packets);
+        fprintf(engine->stats_fh, "    STREAM frame count: %lu\n", stats->out.stream_frames);
+        fprintf(engine->stats_fh, "    STREAM payload size: %lu\n", stats->out.stream_data_sz);
+        fprintf(engine->stats_fh, "    Header bytes: %lu; uncompressed: %lu; ratio %.3lf\n",
+            stats->out.headers_comp, stats->out.headers_uncomp,
+            stats->out.headers_uncomp ?
+            (double) stats->out.headers_comp / (double) stats->out.headers_uncomp
+            : 0);
+        fprintf(engine->stats_fh, "    ACKs: %lu\n", stats->out.acks);
+    }
+#endif
     free(engine);
 }
 

src/liblsquic/lsquic_frame_reader.c

@@ -22,6 +22,7 @@
 #include "lsquic_http1x_if.h"
 #include "lsquic_headers.h"
 #include "lsquic_ev_log.h"
+#include "lsquic_conn.h"
 
 #define LSQUIC_LOGGER_MODULE LSQLM_FRAME_READER
 #define LSQUIC_LOG_CONN_ID lsquic_conn_id(lsquic_stream_conn(fr->fr_stream))
@@ -116,6 +117,9 @@ struct lsquic_frame_reader
      * CONTINUATION frames.  It gets added to as block fragments come in.
      */
     unsigned char                   *fr_header_block;
+#if LSQUIC_CONN_STATS
+    struct conn_stats               *fr_conn_stats;
+#endif
     unsigned                         fr_header_block_sz;
     unsigned                         fr_max_headers_sz; /* 0 means no limit */
     enum frame_reader_flags          fr_flags;
@@ -175,6 +179,9 @@ lsquic_frame_reader_new (enum frame_reader_flags flags,
                     struct lshpack_dec *hdec,
                     const struct frame_reader_callbacks *cb,
                     void *frame_reader_cb_ctx,
+#if LSQUIC_CONN_STATS
+                    struct conn_stats *conn_stats,
+#endif
                     const struct lsquic_hset_if *hsi_if, void *hsi_ctx)
 {
     struct lsquic_frame_reader *fr = malloc(sizeof(*fr));
@@ -202,6 +209,9 @@ lsquic_frame_reader_new (enum frame_reader_flags flags,
     else
         fr->fr_hsi_ctx = hsi_ctx;
     reset_state(fr);
+#if LSQUIC_CONN_STATS
+    fr->fr_conn_stats = conn_stats;
+#endif
     return fr;
 }
 
@@ -538,7 +548,12 @@ decode_and_pass_payload (struct lsquic_frame_reader *fr)
                 fr->fr_hsi_if->hsi_process_header(hset, name_idx, buf,
                                         name_len, buf + name_len, val_len);
             if (err == 0)
+            {
+#if LSQUIC_CONN_STATS
+                fr->fr_conn_stats->in.headers_uncomp += name_len + val_len;
+#endif
                 continue;
+            }
         }
         else
             err = FR_ERR_DECOMPRESS;
@@ -589,6 +604,9 @@ decode_and_pass_payload (struct lsquic_frame_reader *fr)
         fr->fr_callbacks->frc_on_headers(fr->fr_cb_ctx, uh);
     else
         fr->fr_callbacks->frc_on_push_promise(fr->fr_cb_ctx, uh);
+#if LSQUIC_CONN_STATS
+    fr->fr_conn_stats->in.headers_comp += fr->fr_header_block_sz;
+#endif
 
     return 0;
 

src/liblsquic/lsquic_frame_reader.h

@@ -18,6 +18,9 @@ struct lsquic_stream;
 struct lsquic_frame_reader;
 struct lsquic_hset_if;
 struct uncompressed_headers;
+#if LSQUIC_CONN_STATS
+struct conn_stats;
+#endif
 
 
 enum frame_reader_flags
@@ -79,6 +82,9 @@ lsquic_frame_reader_new (enum frame_reader_flags, unsigned max_headers_sz,
                          struct lsquic_mm *, struct lsquic_stream *,
                          fr_stream_read_f, struct lshpack_dec *,
                          const struct frame_reader_callbacks *, void *fr_cb_ctx,
+#if LSQUIC_CONN_STATS
+                         struct conn_stats *conn_stats,
+#endif
                          const struct lsquic_hset_if *, void *hsi_ctx);
 
 int

src/liblsquic/lsquic_frame_writer.c

@@ -21,6 +21,8 @@
 #include "lshpack.h"
 #include "lsquic_mm.h"
 #include "lsquic.h"
+#include "lsquic_int_types.h"
+#include "lsquic_conn.h"
 
 #include "lsquic_frame_writer.h"
 #include "lsquic_frame_common.h"
@@ -65,6 +67,9 @@ struct lsquic_frame_writer
     fw_write_f                  fw_write;
     struct lsquic_mm           *fw_mm;
     struct lshpack_enc         *fw_henc;
+#if LSQUIC_CONN_STATS
+    struct conn_stats          *fw_conn_stats;
+#endif
     struct frame_buf_head       fw_frabs;
     unsigned                    fw_max_frame_sz;
     uint32_t                    fw_max_header_list_sz;  /* 0 means unlimited */
@@ -86,6 +91,9 @@ struct lsquic_frame_writer
 struct lsquic_frame_writer *
 lsquic_frame_writer_new (struct lsquic_mm *mm, struct lsquic_stream *stream,
      unsigned max_frame_sz, struct lshpack_enc *henc, fw_write_f write,
+#if LSQUIC_CONN_STATS
+     struct conn_stats *conn_stats,
+#endif
      int is_server)
 {
     struct lsquic_frame_writer *fw;
@@ -124,6 +132,9 @@ lsquic_frame_writer_new (struct lsquic_mm *mm, struct lsquic_stream *stream,
     else
         fw->fw_flags    = 0;
     TAILQ_INIT(&fw->fw_frabs);
+#if LSQUIC_CONN_STATS
+    fw->fw_conn_stats   = conn_stats;
+#endif
     return fw;
 }
 
@@ -458,6 +469,12 @@ write_headers (struct lsquic_frame_writer *fw,
             s = hfc_write(hfc, buf, end - buf);
             if (s < 0)
                 return s;
+#if LSQUIC_CONN_STATS
+            fw->fw_conn_stats->out.headers_uncomp +=
+                headers->headers[i].name.iov_len
+                    + headers->headers[i].value.iov_len;
+            fw->fw_conn_stats->out.headers_comp += end - buf;
+#endif
         }
         else
         {

src/liblsquic/lsquic_frame_writer.h

@@ -18,13 +18,20 @@ struct lsquic_frame_writer;
 struct lsquic_stream;
 struct lsquic_http_headers;
 struct lsquic_http2_setting;
+#if LSQUIC_CONN_STATS
+struct conn_stats;
+#endif
 
 typedef ssize_t (*fw_write_f)(struct lsquic_stream *, const void *, size_t);
 
 struct lsquic_frame_writer *
 lsquic_frame_writer_new (struct lsquic_mm *, struct lsquic_stream *,
                          unsigned max_frame_sz, struct lshpack_enc *,
-                         fw_write_f, int is_server);
+                         fw_write_f,
+#if LSQUIC_CONN_STATS
+                         struct conn_stats *,
+#endif
+                         int is_server);
 
 void
 lsquic_frame_writer_destroy (struct lsquic_frame_writer *);

src/liblsquic/lsquic_full_conn.c

@@ -188,19 +188,8 @@ struct full_conn
     union {
         struct client_hsk_ctx    client;
     }                            fc_hsk_ctx;
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
-    struct {
+    struct conn_stats            fc_stats;
-        unsigned            n_all_packets_in,
-                            n_packets_out,
-                            n_undec_packets,
-                            n_dup_packets,
-                            n_err_packets;
-        unsigned long       stream_data_sz;
-        unsigned long       n_ticks;
-        unsigned            n_acks_in,
-                            n_acks_proc,
-                            n_acks_merged[2];
-    }                            fc_stats;
 #endif
 #if KEEP_CLOSED_STREAM_HISTORY
     /* Rolling log of histories of closed streams.  Older entries are
@@ -552,6 +541,9 @@ new_conn_common (lsquic_cid_t cid, struct lsquic_engine_public *enpub,
     conn->fc_pub.mm = &enpub->enp_mm;
     conn->fc_pub.lconn = &conn->fc_conn;
     conn->fc_pub.send_ctl = &conn->fc_send_ctl;
+#if LSQUIC_CONN_STATS
+    conn->fc_pub.conn_stats = &conn->fc_stats;
+#endif
     conn->fc_pub.packet_out_malo =
                         lsquic_malo_create(sizeof(struct lsquic_packet_out));
     conn->fc_stream_ifs[STREAM_IF_STD].stream_if     = stream_if;
@@ -599,7 +591,11 @@ new_conn_common (lsquic_cid_t cid, struct lsquic_engine_public *enpub,
     {
         conn->fc_pub.hs = lsquic_headers_stream_new(
             !!(conn->fc_flags & FC_SERVER), conn->fc_enpub,
-                                                     headers_callbacks_ptr, conn);
+                                                     headers_callbacks_ptr,
+#if LSQUIC_CONN_STATS
+                                                    &conn->fc_stats,
+#endif
+                                                     conn);
         if (!conn->fc_pub.hs)
             goto cleanup_on_error;
         conn->fc_stream_ifs[STREAM_IF_HDR].stream_if     = lsquic_headers_stream_if;
@@ -807,18 +803,18 @@ full_conn_ci_destroy (lsquic_conn_t *lconn)
     if (conn->fc_conn.cn_enc_session)
         conn->fc_conn.cn_esf->esf_destroy(conn->fc_conn.cn_enc_session);
     lsquic_malo_destroy(conn->fc_pub.packet_out_malo);
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
     LSQ_NOTICE("# ticks: %lu", conn->fc_stats.n_ticks);
-    LSQ_NOTICE("received %u packets, of which %u were not decryptable, %u were "
+    LSQ_NOTICE("received %lu packets, of which %lu were not decryptable, %lu were "
-        "dups and %u were errors; sent %u packets, avg stream data per outgoing"
+        "dups and %lu were errors; sent %lu packets, avg stream data per outgoing"
         " packet is %lu bytes",
-        conn->fc_stats.n_all_packets_in, conn->fc_stats.n_undec_packets,
+        conn->fc_stats.in.packets, conn->fc_stats.in.undec_packets,
-        conn->fc_stats.n_dup_packets, conn->fc_stats.n_err_packets,
+        conn->fc_stats.in.dup_packets, conn->fc_stats.in.err_packets,
-        conn->fc_stats.n_packets_out,
+        conn->fc_stats.out.packets,
-        conn->fc_stats.stream_data_sz / conn->fc_stats.n_packets_out);
+        conn->fc_stats.out.stream_data_sz / conn->fc_stats.out.packets);
-    LSQ_NOTICE("ACKs: in: %u; processed: %u; merged to: new %u, old %u",
+    LSQ_NOTICE("ACKs: in: %lu; processed: %lu; merged to: new %lu, old %lu",
-        conn->fc_stats.n_acks_in, conn->fc_stats.n_acks_proc,
+        conn->fc_stats.in.n_acks, conn->fc_stats.in.n_acks_proc,
-        conn->fc_stats.n_acks_merged[0], conn->fc_stats.n_acks_merged[1]);
+        conn->fc_stats.in.n_acks_merged[0], conn->fc_stats.in.n_acks_merged[1]);
 #endif
     while ((sitr = STAILQ_FIRST(&conn->fc_stream_ids_to_reset)))
     {
@@ -933,11 +929,11 @@ new_stream (struct full_conn *conn, uint32_t stream_id,
     {
     case LSQUIC_STREAM_HANDSHAKE:
         idx = STREAM_IF_HSK;
-        flags |= SCF_DI_AUTOSWITCH;
+        flags |= SCF_DI_AUTOSWITCH|SCF_CRITICAL;
         break;
     case LSQUIC_STREAM_HEADERS:
         idx = STREAM_IF_HDR;
-        flags |= SCF_DI_AUTOSWITCH;
+        flags |= SCF_DI_AUTOSWITCH|SCF_CRITICAL;
         if (!(conn->fc_flags & FC_HTTP) &&
                                     conn->fc_enpub->enp_settings.es_rw_once)
             flags |= SCF_DISP_RW_ONCE;
@@ -1138,6 +1134,10 @@ process_stream_frame (struct full_conn *conn, lsquic_packet_in_t *packet_in,
     }
     EV_LOG_STREAM_FRAME_IN(LSQUIC_LOG_CONN_ID, stream_frame);
     LSQ_DEBUG("Got stream frame for stream #%u", stream_frame->stream_id);
+#if LSQUIC_CONN_STATS
+    ++conn->fc_stats.in.stream_frames;
+    conn->fc_stats.in.stream_data_sz += stream_frame->data_frame.df_size;
+#endif
 
     enc_level = lsquic_packet_in_enc_level(packet_in);
     if (stream_frame->stream_id != LSQUIC_STREAM_HANDSHAKE
@@ -1349,8 +1349,8 @@ static int
 process_ack (struct full_conn *conn, struct ack_info *acki,
              lsquic_time_t received)
 {
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
-    ++conn->fc_stats.n_acks_proc;
+    ++conn->fc_stats.in.n_acks_proc;
 #endif
     LSQ_DEBUG("Processing ACK");
     if (0 == lsquic_send_ctl_got_ack(&conn->fc_send_ctl, acki, received))
@@ -1470,8 +1470,8 @@ process_ack_frame (struct full_conn *conn, lsquic_packet_in_t *packet_in,
     struct ack_info *const new_acki = conn->fc_pub.mm->acki;
     int parsed_len;
 
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
-    ++conn->fc_stats.n_acks_in;
+    ++conn->fc_stats.in.n_acks;
 #endif
 
     parsed_len = conn->fc_conn.cn_pf->pf_parse_ack_frame(p, len, new_acki);
@@ -1504,8 +1504,8 @@ process_ack_frame (struct full_conn *conn, lsquic_packet_in_t *packet_in,
         case (0 << 1) | (0 << 0):
             if (merge_saved_to_new(&conn->fc_saved_ack_info, new_acki))
             {
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
-                ++conn->fc_stats.n_acks_merged[0]
+                ++conn->fc_stats.in.n_acks_merged[0]
 #endif
                 ;
             }
@@ -1518,8 +1518,8 @@ process_ack_frame (struct full_conn *conn, lsquic_packet_in_t *packet_in,
         case (0 << 1) | (1 << 0):
             if (merge_new_to_saved(&conn->fc_saved_ack_info, new_acki))
             {
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
-                ++conn->fc_stats.n_acks_merged[1]
+                ++conn->fc_stats.in.n_acks_merged[1]
 #endif
                 ;
             }
@@ -1914,8 +1914,8 @@ process_regular_packet (struct full_conn *conn, lsquic_packet_in_t *packet_in)
     reconstruct_packet_number(conn, packet_in);
     EV_LOG_PACKET_IN(LSQUIC_LOG_CONN_ID, packet_in);
 
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
-    ++conn->fc_stats.n_all_packets_in;
+    ++conn->fc_stats.in.packets;
 #endif
 
     /* The packet is decrypted before receive history is updated.  This is
@@ -1934,8 +1934,8 @@ process_regular_packet (struct full_conn *conn, lsquic_packet_in_t *packet_in)
         else
         {
             LSQ_INFO("could not decrypt packet");
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
-            ++conn->fc_stats.n_undec_packets;
+            ++conn->fc_stats.in.undec_packets;
 #endif
             return 0;
         }
@@ -1957,8 +1957,8 @@ process_regular_packet (struct full_conn *conn, lsquic_packet_in_t *packet_in)
         }
         return 0;
     case REC_ST_DUP:
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
-    ++conn->fc_stats.n_dup_packets;
+        ++conn->fc_stats.in.dup_packets;
 #endif
         LSQ_INFO("packet %"PRIu64" is a duplicate", packet_in->pi_packno);
         return 0;
@@ -1966,8 +1966,8 @@ process_regular_packet (struct full_conn *conn, lsquic_packet_in_t *packet_in)
         assert(0);
         /* Fall through */
     case REC_ST_ERR:
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
-    ++conn->fc_stats.n_err_packets;
+        ++conn->fc_stats.in.err_packets;
 #endif
         LSQ_INFO("error processing packet %"PRIu64, packet_in->pi_packno);
         return -1;
@@ -2343,7 +2343,7 @@ process_streams_ready_to_send (struct full_conn *conn)
     lsquic_spi_init(&spi, TAILQ_FIRST(&conn->fc_pub.sending_streams),
         TAILQ_LAST(&conn->fc_pub.sending_streams, lsquic_streams_tailq),
         (uintptr_t) &TAILQ_NEXT((lsquic_stream_t *) NULL, next_send_stream),
-        STREAM_SENDING_FLAGS, conn->fc_conn.cn_cid, "send");
+        STREAM_SENDING_FLAGS, conn->fc_conn.cn_cid, "send", NULL, NULL);
 
     for (stream = lsquic_spi_first(&spi); stream;
                                             stream = lsquic_spi_next(&spi))
@@ -2485,6 +2485,8 @@ static void
 process_streams_read_events (struct full_conn *conn)
 {
     lsquic_stream_t *stream;
+    enum stream_flags service_flags;
+    int needs_service;
     struct stream_prio_iter spi;
 
     if (TAILQ_EMPTY(&conn->fc_pub.read_streams))
@@ -2493,11 +2495,21 @@ process_streams_read_events (struct full_conn *conn)
     lsquic_spi_init(&spi, TAILQ_FIRST(&conn->fc_pub.read_streams),
         TAILQ_LAST(&conn->fc_pub.read_streams, lsquic_streams_tailq),
         (uintptr_t) &TAILQ_NEXT((lsquic_stream_t *) NULL, next_read_stream),
-        STREAM_WANT_READ, conn->fc_conn.cn_cid, "read");
+        STREAM_WANT_READ, conn->fc_conn.cn_cid, "read", NULL, NULL);
 
+    needs_service = 0;
     for (stream = lsquic_spi_first(&spi); stream;
                                             stream = lsquic_spi_next(&spi))
+    {
+        service_flags = stream->stream_flags & STREAM_SERVICE_FLAGS;
         lsquic_stream_dispatch_read_events(stream);
+        needs_service |= service_flags
+                                ^ (stream->stream_flags & STREAM_SERVICE_FLAGS);
+    }
+
+    if (needs_service)
+        service_streams(conn);
+
 }
 
 
@@ -2525,7 +2537,7 @@ process_streams_write_events (struct full_conn *conn, int high_prio)
         TAILQ_LAST(&conn->fc_pub.write_streams, lsquic_streams_tailq),
         (uintptr_t) &TAILQ_NEXT((lsquic_stream_t *) NULL, next_write_stream),
         STREAM_WANT_WRITE|STREAM_WANT_FLUSH, conn->fc_conn.cn_cid,
-        high_prio ? "write-high" : "write-low");
+        high_prio ? "write-high" : "write-low", NULL, NULL);
 
     if (high_prio)
         lsquic_spi_drop_non_high(&spi);
@@ -2633,6 +2645,9 @@ generate_ack_frame (struct full_conn *conn)
         ABORT_ERROR("generating ACK frame failed: %d", errno);
         return;
     }
+#if LSQUIC_CONN_STATS
+    ++conn->fc_stats.out.acks;
+#endif
     EV_LOG_GENERATED_ACK_FRAME(LSQUIC_LOG_CONN_ID, conn->fc_conn.cn_pf,
                         packet_out->po_data + packet_out->po_data_sz, w);
     verify_ack_frame(conn, packet_out->po_data + packet_out->po_data_sz, w);
@@ -2796,7 +2811,7 @@ full_conn_ci_tick (lsquic_conn_t *lconn, lsquic_time_t now)
     }                                                                   \
 } while (0)
 
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
     ++conn->fc_stats.n_ticks;
 #endif
 
@@ -3050,6 +3065,9 @@ full_conn_ci_packet_in (lsquic_conn_t *lconn, lsquic_packet_in_t *packet_in)
 {
     struct full_conn *conn = (struct full_conn *) lconn;
 
+#if LSQUIC_CONN_STATS
+    conn->fc_stats.in.bytes += packet_in->pi_data_sz;
+#endif
     lsquic_alarmset_set(&conn->fc_alset, AL_IDLE,
                 packet_in->pi_received + conn->fc_settings->es_idle_conn_to);
     if (0 == (conn->fc_flags & FC_ERROR))
@@ -3086,8 +3104,9 @@ full_conn_ci_packet_sent (lsquic_conn_t *lconn, lsquic_packet_out_t *packet_out)
     s = lsquic_send_ctl_sent_packet(&conn->fc_send_ctl, packet_out, 1);
     if (s != 0)
         ABORT_ERROR("sent packet failed: %s", strerror(errno));
-#if FULL_CONN_STATS
+#if LSQUIC_CONN_STATS
-    ++conn->fc_stats.n_packets_out;
+    ++conn->fc_stats.out.packets;
+    conn->fc_stats.out.bytes += lsquic_packet_out_sent_sz(lconn, packet_out);
 #endif
 }
 
@@ -3531,6 +3550,18 @@ full_conn_ci_next_tick_time (lsquic_conn_t *lconn)
 }
 
 
+#if LSQUIC_CONN_STATS
+static const struct conn_stats *
+full_conn_ci_get_stats (struct lsquic_conn *lconn)
+{
+    struct full_conn *conn = (struct full_conn *) lconn;
+    return &conn->fc_stats;
+}
+
+
+#endif
+
+
 static const struct headers_stream_callbacks headers_callbacks =
 {
     .hsc_on_headers      = headers_stream_on_incoming_headers,
@@ -3545,6 +3576,9 @@ static const struct headers_stream_callbacks *headers_callbacks_ptr = &headers_c
 
 static const struct conn_iface full_conn_iface = {
     .ci_destroy              =  full_conn_ci_destroy,
+#if LSQUIC_CONN_STATS
+    .ci_get_stats            =  full_conn_ci_get_stats,
+#endif
     .ci_handshake_failed     =  full_conn_ci_handshake_failed,
     .ci_handshake_ok         =  full_conn_ci_handshake_ok,
     .ci_is_tickable          =  full_conn_ci_is_tickable,

src/liblsquic/lsquic_headers_stream.c

@@ -49,6 +49,9 @@ struct headers_stream
             HS_HENC_INITED  = (1 << 1),
     }                                   hs_flags;
     struct lsquic_engine_public        *hs_enpub;
+#if LSQUIC_CONN_STATS
+    struct conn_stats                  *hs_conn_stats;
+#endif
 };
 
 
@@ -89,6 +92,9 @@ headers_on_new_stream (void *stream_if_ctx, lsquic_stream_t *stream)
                                 MAX_HEADERS_SIZE, &hs->hs_enpub->enp_mm,
                                 stream, lsquic_stream_read, &hs->hs_hdec,
                                 frame_callbacks_ptr, hs,
+#if LSQUIC_CONN_STATS
+                        hs->hs_conn_stats,
+#endif
                         hs->hs_enpub->enp_hsi_if, hs->hs_enpub->enp_hsi_ctx);
     if (!hs->hs_fr)
     {
@@ -97,7 +103,11 @@ headers_on_new_stream (void *stream_if_ctx, lsquic_stream_t *stream)
         return NULL;
     }
     hs->hs_fw = lsquic_frame_writer_new(&hs->hs_enpub->enp_mm, stream, 0,
-            &hs->hs_henc, lsquic_stream_write, (hs->hs_flags & HS_IS_SERVER));
+            &hs->hs_henc, lsquic_stream_write,
+#if LSQUIC_CONN_STATS
+            hs->hs_conn_stats,
+#endif
+            (hs->hs_flags & HS_IS_SERVER));
     if (!hs->hs_fw)
     {
         LSQ_WARN("could not create frame writer: %s", strerror(errno));
@@ -196,6 +206,9 @@ lsquic_headers_stream_send_priority (struct headers_stream *hs,
 struct headers_stream *
 lsquic_headers_stream_new (int is_server, struct lsquic_engine_public *enpub,
                            const struct headers_stream_callbacks *callbacks,
+#if LSQUIC_CONN_STATS
+                           struct conn_stats *conn_stats,
+#endif
                            void *cb_ctx)
 {
     struct headers_stream *hs = calloc(1, sizeof(*hs));
@@ -208,6 +221,9 @@ lsquic_headers_stream_new (int is_server, struct lsquic_engine_public *enpub,
     else
         hs->hs_flags = 0;
     hs->hs_enpub     = enpub;
+#if LSQUIC_CONN_STATS
+    hs->hs_conn_stats= conn_stats;
+#endif
     return hs;
 }
 

src/liblsquic/lsquic_headers_stream.h

@@ -18,6 +18,9 @@ struct lsquic_frame_writer;
 struct uncompressed_headers;
 struct lsquic_engine_public;
 struct lsquic_http2_setting;
+#if LSQUIC_CONN_STATS
+struct conn_stats;
+#endif
 
 
 /* Incoming frames result in new objects or events.  Callbacks in this
@@ -40,6 +43,9 @@ struct headers_stream_callbacks
 struct headers_stream *
 lsquic_headers_stream_new (int is_server, struct lsquic_engine_public *,
                            const struct headers_stream_callbacks *,
+#if LSQUIC_CONN_STATS
+                           struct conn_stats *,
+#endif
                            void *hs_cb_ctx);
 
 void

src/liblsquic/lsquic_send_ctl.c

@@ -1117,6 +1117,9 @@ lsquic_send_ctl_next_packet_to_send (lsquic_send_ctl_t *ctl)
     {
         if (packet_out->po_regen_sz < packet_out->po_data_sz)
         {
+#if LSQUIC_CONN_STATS
+            ++ctl->sc_conn_pub->conn_stats->out.retx_packets;
+#endif
             update_for_resending(ctl, packet_out);
             packet_out->po_flags &= ~PO_REPACKNO;
         }

src/liblsquic/lsquic_spi.c

@@ -49,7 +49,9 @@ add_stream_to_spi (struct stream_prio_iter *iter, lsquic_stream_t *stream)
 void
 lsquic_spi_init (struct stream_prio_iter *iter, struct lsquic_stream *first,
         struct lsquic_stream *last, uintptr_t next_ptr_offset,
-        enum stream_flags onlist_mask, lsquic_cid_t cid, const char *name)
+        enum stream_flags onlist_mask, lsquic_cid_t cid, const char *name,
+        int (*filter)(void *filter_ctx, struct lsquic_stream *),
+        void *filter_ctx)
 {
     struct lsquic_stream *stream;
     unsigned count;
@@ -68,14 +70,27 @@ lsquic_spi_init (struct stream_prio_iter *iter, struct lsquic_stream *first,
     stream = first;
     count = 0;
 
-    while (1)
+    if (filter)
-    {
+        while (1)
-        add_stream_to_spi(iter, stream);
+        {
-        ++count;
+            if (filter(filter_ctx, stream))
-        if (stream == last)
+            {
-            break;
+                add_stream_to_spi(iter, stream);
-        stream = NEXT_STREAM(stream, next_ptr_offset);
+                ++count;
-    }
+            }
+            if (stream == last)
+                break;
+            stream = NEXT_STREAM(stream, next_ptr_offset);
+        }
+    else
+        while (1)
+        {
+            add_stream_to_spi(iter, stream);
+            ++count;
+            if (stream == last)
+                break;
+            stream = NEXT_STREAM(stream, next_ptr_offset);
+        }
 
     if (count > 2)
         SPI_DEBUG("initialized; # elems: %u; sets: [ %016"PRIX64", %016"PRIX64

src/liblsquic/lsquic_spi.h

@@ -32,7 +32,9 @@ struct stream_prio_iter
 void
 lsquic_spi_init (struct stream_prio_iter *, struct lsquic_stream *first,
          struct lsquic_stream *last, uintptr_t next_ptr_offset,
-         unsigned onlist_mask, lsquic_cid_t cid, const char *name);
+         unsigned onlist_mask, lsquic_cid_t cid, const char *name,
+         int (*filter)(void *filter_ctx, struct lsquic_stream *),
+         void *filter_ctx);
 
 struct lsquic_stream *
 lsquic_spi_first (struct stream_prio_iter *);

src/liblsquic/lsquic_stream.c

@@ -273,6 +273,8 @@ lsquic_stream_new_ext (uint32_t id, struct lsquic_conn_public *conn_pub,
         lsquic_stream_call_on_new(stream);
     if (ctor_flags & SCF_DISP_RW_ONCE)
         stream->stream_flags |= STREAM_RW_ONCE;
+    if (ctor_flags & SCF_CRITICAL)
+        stream->stream_flags |= STREAM_CRITICAL;
     return stream;
 }
 
@@ -1574,6 +1576,9 @@ stream_write_to_packet (struct frame_gen_ctx *fg_ctx, const size_t size)
         packet_out->po_header_type = stream->tosend_off == 0
                                             ? HETY_INITIAL : HETY_HANDSHAKE;
 
+#if LSQUIC_CONN_STATS
+    const uint64_t begin_off = stream->tosend_off;
+#endif
     off = packet_out->po_data_sz;
     len = pf->pf_gen_stream_frame(
                 packet_out->po_data + packet_out->po_data_sz,
@@ -1596,6 +1601,11 @@ stream_write_to_packet (struct frame_gen_ctx *fg_ctx, const size_t size)
         }
     }
 
+#if LSQUIC_CONN_STATS
+    stream->conn_pub->conn_stats->out.stream_frames += 1;
+    stream->conn_pub->conn_stats->out.stream_data_sz
+                                            += stream->tosend_off - begin_off;
+#endif
     EV_LOG_GENERATED_STREAM_FRAME(LSQUIC_LOG_CONN_ID, pf,
                             packet_out->po_data + packet_out->po_data_sz, len);
     lsquic_send_ctl_incr_pack_sz(send_ctl, packet_out, len);

src/liblsquic/lsquic_stream.h

@@ -62,6 +62,7 @@ struct lsquic_stream
         STREAM_ONNEW_DONE   = (1 <<26),     /* on_new_stream has been called */
         STREAM_AUTOSWITCH   = (1 <<27),
         STREAM_RW_ONCE      = (1 <<28),     /* When set, read/write events are dispatched once per call */
+        STREAM_CRITICAL     = (1 <<29),
     }                               stream_flags;
 
     /* There are more than one reason that a stream may be put onto
@@ -139,6 +140,7 @@ enum stream_ctor_flags
                                    * performance.
                                    */
     SCF_DISP_RW_ONCE  = (1 << 3),
+    SCF_CRITICAL      = (1 << 4), /* This is a critical stream */
 };
 
 lsquic_stream_t *
@@ -274,10 +276,8 @@ struct stream_read_prog_status
     enum stream_flags       srps_flags;
 };
 
-#define lsquic_stream_is_critical(stream) (                                 \
+#define lsquic_stream_is_critical(stream) \
-    (stream)->id == LSQUIC_STREAM_HANDSHAKE ||                              \
+                                ((stream)->stream_flags & STREAM_CRITICAL)
-    ((stream)->id == LSQUIC_STREAM_HEADERS &&                               \
-        (stream)->stream_flags & STREAM_USE_HEADERS))
 
 size_t
 lsquic_stream_mem_used (const struct lsquic_stream *);

test/http_client.c

@@ -31,6 +31,7 @@
 #include <sys/stat.h>
 #include <fcntl.h>
 #include <event2/event.h>
+#include <math.h>
 
 
 #ifndef WIN32
@@ -44,12 +45,16 @@
 #include "prog.h"
 
 #include "../src/liblsquic/lsquic_logger.h"
+#include "../src/liblsquic/lsquic_int_types.h"
+#include "../src/liblsquic/lsquic_util.h"
 
 #define MIN(a, b) ((a) < (b) ? (a) : (b))
 
 /* This is used to exercise generating and sending of priority frames */
 static int randomly_reprioritize_streams;
 
+static int s_display_cert_chain;
+
 /* If this file descriptor is open, the client will accept server push and
  * dump the contents here.  See -u flag.
  */
@@ -61,6 +66,71 @@ static int promise_fd = -1;
  */
 static int g_header_bypass;
 
+static int s_discard_response;
+
+struct sample_stats
+{
+    unsigned        n;
+    unsigned long   min, max;
+    unsigned long   sum;        /* To calculate mean */
+    unsigned long   sum_X2;     /* To calculate stddev */
+};
+
+static struct sample_stats  s_stat_to_conn,     /* Time to connect */
+                            s_stat_ttfb,
+                            s_stat_req;     /* From TTFB to EOS */
+static unsigned s_stat_conns_ok, s_stat_conns_failed;
+static unsigned long s_stat_downloaded_bytes;
+
+static void
+update_sample_stats (struct sample_stats *stats, unsigned long val)
+{
+    LSQ_DEBUG("%s: %p: %lu", __func__, stats, val);
+    if (stats->n)
+    {
+        if (val < stats->min)
+            stats->min = val;
+        else if (val > stats->max)
+            stats->max = val;
+    }
+    else
+    {
+        stats->min = val;
+        stats->max = val;
+    }
+    stats->sum += val;
+    stats->sum_X2 += val * val;
+    ++stats->n;
+}
+
+
+static void
+calc_sample_stats (const struct sample_stats *stats,
+        long double *mean_p, long double *stddev_p)
+{
+    unsigned long mean, tmp;
+
+    if (stats->n)
+    {
+        mean = stats->sum / stats->n;
+        *mean_p = (long double) mean;
+        if (stats->n > 1)
+        {
+            tmp = stats->sum_X2 - stats->n * mean * mean;
+            tmp /= stats->n - 1;
+            *stddev_p = sqrtl((long double) tmp);
+        }
+        else
+            *stddev_p = 0;
+    }
+    else
+    {
+        *mean_p = 0;
+        *stddev_p = 0;
+    }
+}
+
+
 struct lsquic_conn_ctx;
 
 struct path_elem {
@@ -91,10 +161,8 @@ struct http_client_ctx {
     unsigned                     hcc_n_open_conns;
 
     enum {
-        HCC_DISCARD_RESPONSE    = (1 << 0),
         HCC_SEEN_FIN            = (1 << 1),
         HCC_ABORT_ON_INCOMPLETE = (1 << 2),
-        HCC_PROCESSED_HEADERS   = (1 << 3),
     }                            hcc_flags;
     struct prog                 *prog;
 };
@@ -103,6 +171,7 @@ struct lsquic_conn_ctx {
     TAILQ_ENTRY(lsquic_conn_ctx) next_ch;
     lsquic_conn_t       *conn;
     struct http_client_ctx   *client_ctx;
+    lsquic_time_t        ch_created;
     unsigned             ch_n_reqs;    /* This number gets decremented as streams are closed and
                                         * incremented as push promises are accepted.
                                         */
@@ -128,6 +197,8 @@ static void
 hset_dump (const struct hset *, FILE *);
 static void
 hset_destroy (void *hset);
+static void
+display_cert_chain (lsquic_conn_t *);
 
 
 static void
@@ -168,6 +239,7 @@ http_client_on_new_conn (void *stream_if_ctx, lsquic_conn_t *conn)
     TAILQ_INSERT_TAIL(&client_ctx->conn_ctxs, conn_h, next_ch);
     ++conn_h->client_ctx->hcc_n_open_conns;
     create_streams(client_ctx, conn_h);
+    conn_h->ch_created = lsquic_time_now();
     return conn_h;
 }
 
@@ -246,7 +318,21 @@ http_client_on_conn_closed (lsquic_conn_t *conn)
 static void
 http_client_on_hsk_done (lsquic_conn_t *conn, int ok)
 {
+    lsquic_conn_ctx_t *conn_h;
     LSQ_INFO("handshake %s", ok ? "completed successfully" : "failed");
+
+    if (ok && s_display_cert_chain)
+        display_cert_chain(conn);
+
+    if (ok)
+    {
+        conn_h = lsquic_conn_get_ctx(conn);
+        ++s_stat_conns_ok;
+        update_sample_stats(&s_stat_to_conn,
+                                    lsquic_time_now() - conn_h->ch_created);
+    }
+    else
+        ++s_stat_conns_failed;
 }
 
 
@@ -256,8 +342,10 @@ struct lsquic_stream_ctx {
     const char          *path;
     enum {
         HEADERS_SENT    = (1 << 0),
-        CHAIN_DISPLAYED = (1 << 1),
+        PROCESSED_HEADERS = 1 << 1,
     }                    sh_flags;
+    lsquic_time_t        sh_created;
+    lsquic_time_t        sh_ttfb;
     unsigned             count;
     struct lsquic_reader reader;
 };
@@ -278,6 +366,7 @@ http_client_on_new_stream (void *stream_if_ctx, lsquic_stream_t *stream)
     lsquic_stream_ctx_t *st_h = calloc(1, sizeof(*st_h));
     st_h->stream = stream;
     st_h->client_ctx = stream_if_ctx;
+    st_h->sh_created = lsquic_time_now();
     if (st_h->client_ctx->hcc_cur_pe)
     {
         st_h->client_ctx->hcc_cur_pe = TAILQ_NEXT(
@@ -406,12 +495,6 @@ http_client_on_write (lsquic_stream_t *stream, lsquic_stream_ctx_t *st_h)
 {
     ssize_t nw;
 
-    if (!(st_h->sh_flags & CHAIN_DISPLAYED))
-    {
-        display_cert_chain(lsquic_stream_conn(stream));
-        st_h->sh_flags |= CHAIN_DISPLAYED;
-    }
-
     if (st_h->sh_flags & HEADERS_SENT)
     {
         if (st_h->client_ctx->payload && test_reader_size(st_h->reader.lsqr_ctx) > 0)
@@ -459,8 +542,7 @@ http_client_on_read (lsquic_stream_t *stream, lsquic_stream_ctx_t *st_h)
 	srand(GetTickCount());
 #endif
 
-    if (g_header_bypass
+    if (g_header_bypass && !(st_h->sh_flags & PROCESSED_HEADERS))
-            && !(client_ctx->hcc_flags & HCC_PROCESSED_HEADERS))
     {
         hset = lsquic_stream_get_hset(stream);
         if (!hset)
@@ -468,10 +550,14 @@ http_client_on_read (lsquic_stream_t *stream, lsquic_stream_ctx_t *st_h)
             LSQ_ERROR("could not get header set from stream");
             exit(2);
         }
-        if (!(client_ctx->hcc_flags & HCC_DISCARD_RESPONSE))
+        st_h->sh_ttfb = lsquic_time_now();
+        update_sample_stats(&s_stat_ttfb, st_h->sh_ttfb - st_h->sh_created);
+        if (s_discard_response)
+            LSQ_DEBUG("discard response: do not dump headers");
+        else
             hset_dump(hset, stdout);
         hset_destroy(hset);
-        client_ctx->hcc_flags |= HCC_PROCESSED_HEADERS;
+        st_h->sh_flags |= PROCESSED_HEADERS;
     }
 
     do
@@ -479,7 +565,16 @@ http_client_on_read (lsquic_stream_t *stream, lsquic_stream_ctx_t *st_h)
         nread = lsquic_stream_read(stream, buf, sizeof(buf));
         if (nread > 0)
         {
-            if (!(client_ctx->hcc_flags & HCC_DISCARD_RESPONSE))
+            s_stat_downloaded_bytes += nread;
+            if (!g_header_bypass && !(st_h->sh_flags & PROCESSED_HEADERS))
+            {
+                /* First read is assumed to be the first byte */
+                st_h->sh_ttfb = lsquic_time_now();
+                update_sample_stats(&s_stat_ttfb,
+                                    st_h->sh_ttfb - st_h->sh_created);
+                st_h->sh_flags |= PROCESSED_HEADERS;
+            }
+            if (!s_discard_response)
                 write(STDOUT_FILENO, buf, nread);
             if (randomly_reprioritize_streams && (st_h->count++ & 0x3F) == 0)
             {
@@ -496,6 +591,7 @@ http_client_on_read (lsquic_stream_t *stream, lsquic_stream_ctx_t *st_h)
         }
         else if (0 == nread)
         {
+            update_sample_stats(&s_stat_req, lsquic_time_now() - st_h->sh_ttfb);
             client_ctx->hcc_flags |= HCC_SEEN_FIN;
             lsquic_stream_shutdown(stream, 0);
             break;
@@ -597,6 +693,9 @@ usage (const char *prog)
 "   -C DIR      Certificate store.  If specified, server certificate will\n"
 "                 be verified.\n"
 #endif
+"   -a          Display server certificate chain after successful handshake.\n"
+"   -t          Print stats to stdout.\n"
+"   -T FILE     Print stats to FILE.  If FILE is -, print stats to stdout.\n"
             , prog);
 }
 
@@ -708,8 +807,9 @@ hset_create (void *hsi_ctx, int is_push_promise)
 {
     struct hset *hset;
 
-    hset = malloc(sizeof(*hset));
+    if (s_discard_response)
-    if (hset)
+        return (void *) 1;
+    else if ((hset = malloc(sizeof(*hset))))
     {
         STAILQ_INIT(hset);
         return hset;
@@ -727,6 +827,14 @@ hset_add_header (void *hset_p, unsigned name_idx,
     struct hset *hset = hset_p;
     struct hset_elem *el;
 
+    if (name)
+        s_stat_downloaded_bytes += name_len + value_len + 4;    /* ": \r\n" */
+    else
+        s_stat_downloaded_bytes += 2;   /* \r\n "*/
+
+    if (s_discard_response)
+        return LSQUIC_HDR_OK;
+
     if (!name)  /* This signals end of headers.  We do no post-processing. */
         return LSQUIC_HDR_OK;
 
@@ -756,14 +864,17 @@ hset_destroy (void *hset_p)
     struct hset *hset = hset_p;
     struct hset_elem *el, *next;
 
-    for (el = STAILQ_FIRST(hset); el; el = next)
+    if (!s_discard_response)
     {
-        next = STAILQ_NEXT(el, next);
+        for (el = STAILQ_FIRST(hset); el; el = next)
-        free(el->name);
+        {
-        free(el->value);
+            next = STAILQ_NEXT(el, next);
-        free(el);
+            free(el->name);
+            free(el->value);
+            free(el);
+        }
+        free(hset);
     }
-    free(hset);
 }
 
 
@@ -796,10 +907,25 @@ static const struct lsquic_hset_if header_bypass_api =
 };
 
 
+static void
+display_stat (FILE *out, const struct sample_stats *stats, const char *name)
+{
+    long double mean, stddev;
+
+    calc_sample_stats(stats, &mean, &stddev);
+    fprintf(out, "%s: n: %u; min: %.2Lf ms; max: %.2Lf ms; mean: %.2Lf ms; "
+        "sd: %.2Lf ms\n", name, stats->n, (long double) stats->min / 1000,
+        (long double) stats->max / 1000, mean / 1000, stddev / 1000);
+}
+
+
 int
 main (int argc, char **argv)
 {
     int opt, s;
+    lsquic_time_t start_time;
+    FILE *stats_fh = NULL;
+    long double elapsed;
     struct http_client_ctx client_ctx;
     struct stat st;
     struct path_elem *pe;
@@ -825,11 +951,14 @@ main (int argc, char **argv)
 
     while (-1 != (opt = getopt(argc, argv, PROG_OPTS "46Br:R:IKu:EP:M:n:w:H:p:h"
 #ifndef WIN32
-                                                                          "C:"
+                                                                      "C:atT:"
 #endif
                                                                             )))
     {
         switch (opt) {
+        case 'a':
+            ++s_display_cert_chain;
+            break;
         case '4':
         case '6':
             prog.prog_ipver = opt - '0';
@@ -843,7 +972,7 @@ main (int argc, char **argv)
             client_ctx.hcc_flags |= HCC_ABORT_ON_INCOMPLETE;
             break;
         case 'K':
-            client_ctx.hcc_flags |= HCC_DISCARD_RESPONSE;
+            ++s_discard_response;
             break;
         case 'u':   /* Accept p<U>sh promise */
             promise_fd = open(optarg, O_WRONLY|O_CREAT|O_TRUNC, 0644);
@@ -902,18 +1031,39 @@ main (int argc, char **argv)
             prog.prog_api.ea_verify_ctx = optarg;
             break;
 #endif
+        case 't':
+            stats_fh = stdout;
+            break;
+        case 'T':
+            if (0 == strcmp(optarg, "-"))
+                stats_fh = stdout;
+            else
+            {
+                stats_fh = fopen(optarg, "w");
+                if (!stats_fh)
+                {
+                    perror("fopen");
+                    exit(1);
+                }
+            }
+            break;
         default:
             if (0 != prog_set_opt(&prog, opt, optarg))
                 exit(1);
         }
     }
 
+#if LSQUIC_CONN_STATS
+    prog.prog_api.ea_stats_fh = stats_fh;
+#endif
+
     if (TAILQ_EMPTY(&client_ctx.hcc_path_elems))
     {
         fprintf(stderr, "Specify at least one path using -p option\n");
         exit(1);
     }
 
+    start_time = lsquic_time_now();
     if (0 != prog_prep(&prog))
     {
         LSQ_ERROR("could not prep");
@@ -925,6 +1075,21 @@ main (int argc, char **argv)
     LSQ_DEBUG("entering event loop");
 
     s = prog_run(&prog);
+
+    if (stats_fh)
+    {
+        elapsed = (long double) (lsquic_time_now() - start_time) / 1000000;
+        fprintf(stats_fh, "overall statistics as calculated by %s:\n", argv[0]);
+        display_stat(stats_fh, &s_stat_to_conn, "time for connect");
+        display_stat(stats_fh, &s_stat_req, "time for request");
+        display_stat(stats_fh, &s_stat_ttfb, "time to 1st byte");
+        fprintf(stats_fh, "downloaded %lu application bytes in %.3Lf seconds\n",
+            s_stat_downloaded_bytes, elapsed);
+        fprintf(stats_fh, "%.2Lf reqs/sec; %.0Lf bytes/sec\n",
+            (long double) s_stat_req.n / elapsed,
+            (long double) s_stat_downloaded_bytes / elapsed);
+    }
+
     prog_cleanup(&prog);
     if (promise_fd >= 0)
         (void) close(promise_fd);

test/unittests/test_frame_chop.c

@@ -27,6 +27,10 @@
 #include "lsquic_frame_common.h"
 #include "lsquic_frame_writer.h"
 #include "lsquic_frame_reader.h"
+#if LSQUIC_CONN_STATS
+#include "lsquic_int_types.h"
+#include "lsquic_conn.h"
+#endif
 
 
 struct lsquic_stream
@@ -98,11 +102,20 @@ test_chop (unsigned max_write_sz)
     struct lshpack_enc henc;
     int s;
 
+#if LSQUIC_CONN_STATS
+    struct conn_stats conn_stats;
+    memset(&conn_stats, 0, sizeof(conn_stats));
+#endif
+
     lsquic_mm_init(&mm);
     lshpack_enc_init(&henc);
     stream = stream_new(max_write_sz);
 
-    fw = lsquic_frame_writer_new(&mm, stream, 0, &henc, stream_write, 0);
+    fw = lsquic_frame_writer_new(&mm, stream, 0, &henc, stream_write,
+#if LSQUIC_CONN_STATS
+                                 &conn_stats,
+#endif
+                                0);
 
     struct lsquic_http_header header_arr[] =
     {

test/unittests/test_frame_reader.c

@@ -23,6 +23,10 @@
 #include "lsquic_stream.h"
 #include "lsquic_conn_public.h"
 #include "lsquic_logger.h"
+#if LSQUIC_CONN_STATS
+#include "lsquic_int_types.h"
+#include "lsquic_conn.h"
+#endif
 
 #include "lsquic_frame_reader.h"
 #include "lsquic_headers.h"
@@ -1105,6 +1109,11 @@ test_one_frt (const struct frame_reader_test *frt)
     struct lsquic_stream stream;
     int s;
 
+#if LSQUIC_CONN_STATS
+    struct conn_stats conn_stats;
+    memset(&conn_stats, 0, sizeof(conn_stats));
+#endif
+
     memset(&stream, 0, sizeof(stream));
     memset(&lconn, 0, sizeof(lconn));
     memset(&conn_pub, 0, sizeof(conn_pub));
@@ -1125,6 +1134,9 @@ test_one_frt (const struct frame_reader_test *frt)
 
         fr = lsquic_frame_reader_new(frt->frt_fr_flags, frt->frt_max_headers_sz,
                 &mm, &stream, read_from_stream, &hdec, &frame_callbacks, &g_cb_ctx,
+#if LSQUIC_CONN_STATS
+                &conn_stats,
+#endif
                 lsquic_http1x_if, NULL);
         do
         {

test/unittests/test_frame_rw.c

@@ -29,6 +29,10 @@
 #include "lsquic_frame_reader.h"
 #include "lsquic_headers.h"
 #include "lsquic_http1x_if.h"
+#if LSQUIC_CONN_STATS
+#include "lsquic_int_types.h"
+#include "lsquic_conn.h"
+#endif
 
 
 struct lsquic_stream
@@ -192,6 +196,10 @@ test_rw (unsigned max_frame_sz)
     struct lshpack_enc henc;
     struct lshpack_dec hdec;
     int s;
+#if LSQUIC_CONN_STATS
+    struct conn_stats conn_stats;
+    memset(&conn_stats, 0, sizeof(conn_stats));
+#endif
 
     lsquic_mm_init(&mm);
     lshpack_enc_init(&henc);
@@ -200,7 +208,11 @@ test_rw (unsigned max_frame_sz)
     stream->sm_max_sz = 1;
 
     fw = lsquic_frame_writer_new(&mm, stream, max_frame_sz, &henc,
-                                 stream_write, 0);
+                                 stream_write,
+#if LSQUIC_CONN_STATS
+                                 &conn_stats,
+#endif
+                                 0);
 
     struct lsquic_http_headers headers = {
         .count   = N_HEADERS,
@@ -216,7 +228,11 @@ test_rw (unsigned max_frame_sz)
         stream->sm_off = 0;
 
         fr = lsquic_frame_reader_new(0, 0, &mm, stream, read_from_stream, &hdec,
-                                &frame_callbacks, &uh, lsquic_http1x_if, NULL);
+                                &frame_callbacks, &uh,
+#if LSQUIC_CONN_STATS
+                                &conn_stats,
+#endif
+                                lsquic_http1x_if, NULL);
         do
         {
             s = lsquic_frame_reader_read(fr);

test/unittests/test_frame_writer.c

@@ -14,6 +14,14 @@
 #include "lsquic_mm.h"
 #include "lsquic_frame_common.h"
 #include "lsquic_frame_writer.h"
+#if LSQUIC_CONN_STATS
+#include "lsquic_int_types.h"
+#include "lsquic_conn.h"
+#endif
+
+#if LSQUIC_CONN_STATS
+static struct conn_stats s_conn_stats;
+#endif
 
 
 static struct {
@@ -65,11 +73,19 @@ test_max_frame_size (void)
     for (max_size = 1; max_size < 6 /* one settings frame */; ++max_size)
     {
         fw = lsquic_frame_writer_new(&mm, NULL, max_size, &henc,
-                                     output_write, 0);
+                                     output_write,
+#if LSQUIC_CONN_STATS
+                                     &s_conn_stats,
+#endif
+                                     0);
         assert(!fw);
     }
 
-    fw = lsquic_frame_writer_new(&mm, NULL, max_size, &henc, output_write, 0);
+    fw = lsquic_frame_writer_new(&mm, NULL, max_size, &henc, output_write,
+#if LSQUIC_CONN_STATS
+                                     &s_conn_stats,
+#endif
+                                0);
     assert(fw);
 
     lsquic_frame_writer_destroy(fw);
@@ -88,7 +104,11 @@ test_one_header (void)
 
     lshpack_enc_init(&henc);
     lsquic_mm_init(&mm);
-    fw = lsquic_frame_writer_new(&mm, NULL, 0x200, &henc, output_write, 0);
+    fw = lsquic_frame_writer_new(&mm, NULL, 0x200, &henc, output_write,
+#if LSQUIC_CONN_STATS
+                                     &s_conn_stats,
+#endif
+                                0);
     reset_output(0);
 
     struct lsquic_http_header header_arr[] =
@@ -148,7 +168,11 @@ test_oversize_header (void)
 
     lshpack_enc_init(&henc);
     lsquic_mm_init(&mm);
-    fw = lsquic_frame_writer_new(&mm, NULL, 0x200, &henc, output_write, 0);
+    fw = lsquic_frame_writer_new(&mm, NULL, 0x200, &henc, output_write,
+#if LSQUIC_CONN_STATS
+                                     &s_conn_stats,
+#endif
+                                0);
     reset_output(0);
 
     value = malloc(big_len);
@@ -186,7 +210,11 @@ test_continuations (void)
 
     lshpack_enc_init(&henc);
     lsquic_mm_init(&mm);
-    fw = lsquic_frame_writer_new(&mm, NULL, 6, &henc, output_write, 0);
+    fw = lsquic_frame_writer_new(&mm, NULL, 6, &henc, output_write,
+#if LSQUIC_CONN_STATS
+                                 &s_conn_stats,
+#endif
+                                0);
     reset_output(0);
 
 /*
@@ -271,7 +299,11 @@ test_settings_short (void)
     struct lsquic_mm mm;
 
     lsquic_mm_init(&mm);
-    fw = lsquic_frame_writer_new(&mm, NULL, 7, NULL, output_write, 0);
+    fw = lsquic_frame_writer_new(&mm, NULL, 7, NULL, output_write,
+#if LSQUIC_CONN_STATS
+                                     &s_conn_stats,
+#endif
+                                0);
 
     {
         reset_output(0);
@@ -315,7 +347,11 @@ test_settings_normal (void)
     struct lsquic_mm mm;
 
     lsquic_mm_init(&mm);
-    fw = lsquic_frame_writer_new(&mm, NULL, 0, NULL, output_write, 0);
+    fw = lsquic_frame_writer_new(&mm, NULL, 0, NULL, output_write,
+#if LSQUIC_CONN_STATS
+                                     &s_conn_stats,
+#endif
+                                    0);
 
     {
         reset_output(0);
@@ -372,7 +408,11 @@ test_priority (void)
     struct lsquic_mm mm;
 
     lsquic_mm_init(&mm);
-    fw = lsquic_frame_writer_new(&mm, NULL, 6, NULL, output_write, 0);
+    fw = lsquic_frame_writer_new(&mm, NULL, 6, NULL, output_write,
+#if LSQUIC_CONN_STATS
+                                 &s_conn_stats,
+#endif
+                                0);
 
     s = lsquic_frame_writer_write_priority(fw, 3, 0, 1UL << 31, 256);
     assert(s < 0);  /* Invalid dependency stream ID */
@@ -431,7 +471,11 @@ test_errors (void)
 
     lshpack_enc_init(&henc);
     lsquic_mm_init(&mm);
-    fw = lsquic_frame_writer_new(&mm, NULL, 0x200, &henc, output_write, 1);
+    fw = lsquic_frame_writer_new(&mm, NULL, 0x200, &henc, output_write,
+#if LSQUIC_CONN_STATS
+                                     &s_conn_stats,
+#endif
+                                1);
     reset_output(0);
 
     {
@@ -481,7 +525,11 @@ test_push_promise (void)
 
     lshpack_enc_init(&henc);
     lsquic_mm_init(&mm);
-    fw = lsquic_frame_writer_new(&mm, NULL, 0x200, &henc, output_write, 1);
+    fw = lsquic_frame_writer_new(&mm, NULL, 0x200, &henc, output_write,
+#if LSQUIC_CONN_STATS
+                                     &s_conn_stats,
+#endif
+                                1);
     reset_output(0);
 
 /*

test/unittests/test_spi.c

@@ -72,7 +72,7 @@ test_same_priority (unsigned priority)
     lsquic_spi_init(&spi, TAILQ_FIRST(&streams),
         TAILQ_LAST(&streams, lsquic_streams_tailq),
         (uintptr_t) &TAILQ_NEXT((lsquic_stream_t *) NULL, next_write_stream),
-        flags, 0, __func__);
+        flags, 0, __func__, NULL, NULL);
 
     stream = lsquic_spi_first(&spi);
     assert(stream == stream_arr[0]);
@@ -88,7 +88,7 @@ test_same_priority (unsigned priority)
     /* Test reinitialization: */
     lsquic_spi_init(&spi, stream_arr[0], stream_arr[1],
         (uintptr_t) &TAILQ_NEXT((lsquic_stream_t *) NULL, next_write_stream),
-        flags, 0, __func__);
+        flags, 0, __func__, NULL, NULL);
     stream = lsquic_spi_first(&spi);
     assert(stream == stream_arr[0]);
     stream = lsquic_spi_next(&spi);
@@ -122,7 +122,7 @@ test_different_priorities (int *priority)
     lsquic_spi_init(&spi, TAILQ_FIRST(&streams),
         TAILQ_LAST(&streams, lsquic_streams_tailq),
         (uintptr_t) &TAILQ_NEXT((lsquic_stream_t *) NULL, next_send_stream),
-        flags, 0, __func__);
+        flags, 0, __func__, NULL, NULL);
 
     for (prev_prio = -1, count = 0, stream = lsquic_spi_first(&spi); stream;
                                         stream = lsquic_spi_next(&spi), ++count)
@@ -209,7 +209,7 @@ test_drop (const struct drop_test *test)
         lsquic_spi_init(&spi, TAILQ_FIRST(&streams),
             TAILQ_LAST(&streams, lsquic_streams_tailq),
             (uintptr_t) &TAILQ_NEXT((lsquic_stream_t *) NULL, next_write_stream),
-            STREAM_WRITE_Q_FLAGS, 0, __func__);
+            STREAM_WRITE_Q_FLAGS, 0, __func__, NULL, NULL);
 
         if (drop_high)
             lsquic_spi_drop_high(&spi);
@@ -229,6 +229,69 @@ test_drop (const struct drop_test *test)
 }
 
 
+#define MAGIC 0x12312312U
+
+struct my_filter_ctx
+{
+    unsigned magic;
+};
+
+
+static int
+filter_out_odd_priorities (void *ctx, lsquic_stream_t *stream)
+{
+    struct my_filter_ctx *fctx = ctx;
+    assert(fctx->magic == MAGIC);
+    return 0 == (stream->sm_priority & 1);
+}
+
+
+static void
+test_different_priorities_filter_odd (int *priority)
+{
+    struct lsquic_streams_tailq streams;
+    unsigned flags = 0xC000;     /* Arbitrary value */
+    lsquic_stream_t *stream;
+    int prio, prev_prio, count, n_streams = 0;
+
+    TAILQ_INIT(&streams);
+
+    for ( ; *priority >= 0; ++priority)
+    {
+        assert(*priority < 256);
+        stream = new_stream(*priority);
+        TAILQ_INSERT_TAIL(&streams, stream, next_send_stream);
+        stream->stream_flags |= flags;
+        ++n_streams;
+    }
+
+    struct my_filter_ctx my_filter_ctx = { MAGIC };
+
+    lsquic_spi_init(&spi, TAILQ_FIRST(&streams),
+        TAILQ_LAST(&streams, lsquic_streams_tailq),
+        (uintptr_t) &TAILQ_NEXT((lsquic_stream_t *) NULL, next_send_stream),
+        flags, 0, NULL, filter_out_odd_priorities, &my_filter_ctx);
+
+    for (prev_prio = -1, count = 0, stream = lsquic_spi_first(&spi); stream;
+                                        stream = lsquic_spi_next(&spi), ++count)
+    {
+        prio = stream->sm_priority;
+        assert(0 == (prio & 1));
+        assert(prio >= prev_prio);
+        if (prio > prev_prio)
+            prev_prio = prio;
+    }
+
+    assert(count < n_streams);
+
+    while ((stream = TAILQ_FIRST(&streams)))
+    {
+        TAILQ_REMOVE(&streams, stream, next_send_stream);
+        free(stream);
+    }
+}
+
+
 int
 main (int argc, char **argv)
 {
@@ -259,6 +322,11 @@ main (int argc, char **argv)
         test_different_priorities(prio);
     }
 
+    {
+        int prio[] = { 200, 202, 240, 201, 200, 199, -1 };
+        test_different_priorities_filter_odd(prio);
+    }
+
     unsigned n;
     for (n = 0; n < sizeof(drop_tests) / sizeof(drop_tests[0]); ++n)
         test_drop(&drop_tests[n]);