Release 2.16.1

- [FEATURE] Use "no-progress timeout" after which connection is closed.
- [BUGFIX] Select new SCID when current SCID is retired.
- [BUGFIX] Don't warn about dropped Initial packet sequence gaps during
  mini/full handoff.
- [BUGFIX] Send correct conn error when HTTP/3 frame is truncated.
- [BUGFIX] Mini conn: consider amplification when deciding to return
  TICK_SEND.
- [BUGFIX] Don't double-count tag length in amplification logic.
- [BUGFIX] Don't squeeze out lone path challenges.
- [BUGFIX] Log messages dealing with scheduled packet queue squeezing.
- [BUGFIX] don't wipe current path if no path challenge responses
  come back.
- [BUGFIX] When path is reset, don't lose path_id which is used for
  logging.
- Downgrade flow control violations to info log level from warnings.
- Fix connection cap extra check, avoid checks in nested calls.
- Fix some unit tests when extra checks are enabled.
- Use ls-hpack 2.2.1.
- Turn off unconditional extra checks for IETF clients.
- Extra checks: don't verify sent size of hello packets.  Client
  changes DCID length and this check will fail.
This commit is contained in:
Dmitri Tikhonov 2020-06-09 11:55:56 -04:00
parent 6bca16f0d2
commit 8ae5ecb45e
22 changed files with 369 additions and 54 deletions

View file

@ -99,7 +99,7 @@ lsquic_cfcw_incr_max_recv_off (struct lsquic_cfcw *fc, uint64_t incr)
}
else
{
LSQ_WARN("flow control violation: received at offset %"PRIu64", while "
LSQ_INFO("flow control violation: received at offset %"PRIu64", while "
"flow control receive offset is %"PRIu64,
fc->cf_max_recv_off + incr, fc->cf_recv_off);
return 0;

View file

@ -56,12 +56,15 @@ struct lsquic_conn_public {
const struct network_path *path;
#if LSQUIC_EXTRA_CHECKS
unsigned long stream_frame_bytes;
unsigned wtp_level; /* wtp: Write To Packets */
#endif
/* "unsigned" is wide enough: these values are only used for amplification
* limit before initial path is validated.
*/
unsigned bytes_in; /* successfully processed */
unsigned bytes_out;
/* Used for no-progress timeout */
lsquic_time_t last_tick, last_prog;
};
#endif

View file

@ -295,6 +295,8 @@ lsquic_engine_init_settings (struct lsquic_engine_settings *settings,
settings->es_init_max_streams_uni
= LSQUIC_DF_INIT_MAX_STREAMS_UNI_SERVER;
settings->es_ping_period = 0;
settings->es_noprogress_timeout
= LSQUIC_DF_NOPROGRESS_TIMEOUT_SERVER;
}
else
{
@ -311,6 +313,8 @@ lsquic_engine_init_settings (struct lsquic_engine_settings *settings,
settings->es_init_max_streams_uni
= LSQUIC_DF_INIT_MAX_STREAMS_UNI_CLIENT;
settings->es_ping_period = LSQUIC_DF_PING_PERIOD;
settings->es_noprogress_timeout
= LSQUIC_DF_NOPROGRESS_TIMEOUT_CLIENT;
}
settings->es_max_streams_in = LSQUIC_DF_MAX_STREAMS_IN;
settings->es_idle_conn_to = LSQUIC_DF_IDLE_CONN_TO;
@ -601,6 +605,9 @@ lsquic_engine_new (unsigned flags,
if (!engine->pub.enp_tokgen)
return NULL;
engine->pub.enp_crand = &engine->crand;
if (engine->pub.enp_settings.es_noprogress_timeout)
engine->pub.enp_noprog_timeout
= engine->pub.enp_settings.es_noprogress_timeout * 1000000;
if (flags & ENG_SERVER)
{
engine->pr_queue = lsquic_prq_create(

View file

@ -66,6 +66,8 @@ struct lsquic_engine_public {
struct crand *enp_crand;
struct evp_aead_ctx_st *enp_retry_aead_ctx;
unsigned char *enp_alpn; /* May be set if not HTTP */
/* es_noprogress_timeout converted to microseconds for speed */
lsquic_time_t enp_noprog_timeout;
};
/* Put connection onto the Tickable Queue if it is not already on it. If

View file

@ -112,6 +112,7 @@ enum full_conn_flags {
FC_ABORT_COMPLAINED
= (1 <<23),
FC_GOT_SREJ = (1 <<24), /* Don't schedule ACK alarm */
FC_NOPROG_TIMEOUT = (1 <<25),
};
#define FC_IMMEDIATE_CLOSE_FLAGS \
@ -686,6 +687,8 @@ new_conn_common (lsquic_cid_t cid, struct lsquic_engine_public *enpub,
if (conn->fc_settings->es_support_push)
conn->fc_flags |= FC_SUPPORT_PUSH;
conn->fc_conn.cn_n_cces = sizeof(conn->fc_cces) / sizeof(conn->fc_cces[0]);
if (conn->fc_settings->es_noprogress_timeout)
conn->fc_flags |= FC_NOPROG_TIMEOUT;
return conn;
cleanup_on_error:
@ -2481,9 +2484,22 @@ idle_alarm_expired (enum alarm_id al_id, void *ctx, lsquic_time_t expiry,
lsquic_time_t now)
{
struct full_conn *conn = ctx;
LSQ_DEBUG("connection timed out");
EV_LOG_CONN_EVENT(LSQUIC_LOG_CONN_ID, "connection timed out");
conn->fc_flags |= FC_TIMED_OUT;
if ((conn->fc_flags & FC_NOPROG_TIMEOUT)
&& conn->fc_pub.last_prog + conn->fc_enpub->enp_noprog_timeout < now)
{
LSQ_DEBUG("connection timed out due to lack of progress");
EV_LOG_CONN_EVENT(LSQUIC_LOG_CONN_ID, "connection timed out due to "
"lack of progress");
/* Different flag so that CONNECTION_CLOSE frame is sent */
conn->fc_flags |= FC_ABORTED;
}
else
{
LSQ_DEBUG("connection timed out");
EV_LOG_CONN_EVENT(LSQUIC_LOG_CONN_ID, "connection timed out");
conn->fc_flags |= FC_TIMED_OUT;
}
}
@ -3242,6 +3258,31 @@ full_conn_ci_can_write_ack (struct lsquic_conn *lconn)
}
/* This should be called before lsquic_alarmset_ring_expired() */
static void
maybe_set_noprogress_alarm (struct full_conn *conn, lsquic_time_t now)
{
lsquic_time_t exp;
if (conn->fc_flags & FC_NOPROG_TIMEOUT)
{
if (conn->fc_pub.last_tick)
{
exp = conn->fc_pub.last_prog + conn->fc_enpub->enp_noprog_timeout;
if (!lsquic_alarmset_is_set(&conn->fc_alset, AL_IDLE)
|| exp < conn->fc_alset.as_expiry[AL_IDLE])
lsquic_alarmset_set(&conn->fc_alset, AL_IDLE, exp);
conn->fc_pub.last_tick = now;
}
else
{
conn->fc_pub.last_tick = now;
conn->fc_pub.last_prog = now;
}
}
}
static enum tick_st
full_conn_ci_tick (lsquic_conn_t *lconn, lsquic_time_t now)
{
@ -3296,6 +3337,8 @@ full_conn_ci_tick (lsquic_conn_t *lconn, lsquic_time_t now)
conn->fc_flags &= ~FC_HAVE_SAVED_ACK;
}
maybe_set_noprogress_alarm(conn, now);
lsquic_send_ctl_tick_in(&conn->fc_send_ctl, now);
lsquic_send_ctl_set_buffer_stream_packets(&conn->fc_send_ctl, 1);
CLOSE_IF_NECESSARY();
@ -3520,6 +3563,20 @@ full_conn_ci_tick (lsquic_conn_t *lconn, lsquic_time_t now)
}
static void
set_earliest_idle_alarm (struct full_conn *conn, lsquic_time_t idle_conn_to)
{
lsquic_time_t exp;
if (conn->fc_pub.last_prog
&& (assert(conn->fc_flags & FC_NOPROG_TIMEOUT),
exp = conn->fc_pub.last_prog + conn->fc_enpub->enp_noprog_timeout,
exp < idle_conn_to))
idle_conn_to = exp;
lsquic_alarmset_set(&conn->fc_alset, AL_IDLE, idle_conn_to);
}
static void
full_conn_ci_packet_in (lsquic_conn_t *lconn, lsquic_packet_in_t *packet_in)
{
@ -3528,7 +3585,7 @@ full_conn_ci_packet_in (lsquic_conn_t *lconn, lsquic_packet_in_t *packet_in)
#if LSQUIC_CONN_STATS
conn->fc_stats.in.bytes += packet_in->pi_data_sz;
#endif
lsquic_alarmset_set(&conn->fc_alset, AL_IDLE,
set_earliest_idle_alarm(conn,
packet_in->pi_received + conn->fc_settings->es_idle_conn_to);
if (0 == (conn->fc_flags & FC_ERROR))
if (0 != process_incoming_packet(conn, packet_in))

View file

@ -141,6 +141,7 @@ enum ifull_conn_flags
enum more_flags
{
MF_VALIDATE_PATH = 1 << 0,
MF_NOPROG_TIMEOUT = 1 << 1,
};
@ -476,6 +477,9 @@ static int
insert_new_dcid (struct ietf_full_conn *, uint64_t seqno,
const lsquic_cid_t *, const unsigned char *token, int update_cur_dcid);
static struct conn_cid_elem *
find_cce_by_cid (struct ietf_full_conn *, const lsquic_cid_t *);
static unsigned
highest_bit_set (unsigned sz)
{
@ -533,9 +537,22 @@ idle_alarm_expired (enum alarm_id al_id, void *ctx, lsquic_time_t expiry,
lsquic_time_t now)
{
struct ietf_full_conn *const conn = (struct ietf_full_conn *) ctx;
LSQ_DEBUG("connection timed out");
EV_LOG_CONN_EVENT(LSQUIC_LOG_CONN_ID, "connection timed out");
conn->ifc_flags |= IFC_TIMED_OUT;
if ((conn->ifc_mflags & MF_NOPROG_TIMEOUT)
&& conn->ifc_pub.last_prog + conn->ifc_enpub->enp_noprog_timeout < now)
{
EV_LOG_CONN_EVENT(LSQUIC_LOG_CONN_ID, "connection timed out due to "
"lack of progress");
/* Different flag so that CONNECTION_CLOSE frame is sent */
ABORT_QUIETLY(0, TEC_APPLICATION_ERROR,
"connection timed out due to lack of progress");
}
else
{
LSQ_DEBUG("connection timed out");
EV_LOG_CONN_EVENT(LSQUIC_LOG_CONN_ID, "connection timed out");
conn->ifc_flags |= IFC_TIMED_OUT;
}
}
@ -564,6 +581,14 @@ cid_throt_alarm_expired (enum alarm_id al_id, void *ctx,
}
static void
wipe_path (struct ietf_full_conn *conn, unsigned path_id)
{
memset(&conn->ifc_paths[path_id], 0, sizeof(conn->ifc_paths[0]));
conn->ifc_paths[path_id].cop_path.np_path_id = path_id;
}
static void
path_chal_alarm_expired (enum alarm_id al_id, void *ctx,
lsquic_time_t expiry, lsquic_time_t now, unsigned path_id)
@ -577,12 +602,15 @@ path_chal_alarm_expired (enum alarm_id al_id, void *ctx,
LSQ_DEBUG("path #%u challenge expired, schedule another one", path_id);
conn->ifc_send_flags |= SF_SEND_PATH_CHAL << path_id;
}
else
else if (conn->ifc_cur_path_id != path_id)
{
LSQ_INFO("migration to path #%u failed after none of %u path "
"challenges received responses", path_id, copath->cop_n_chals);
memset(copath, 0, sizeof(*copath));
wipe_path(conn, path_id);
}
else
LSQ_INFO("no path challenge responses on current path %u, stop "
"sending path challenges", path_id);
}
@ -1132,6 +1160,8 @@ ietf_full_conn_init (struct ietf_full_conn *conn,
conn->ifc_ping_unretx_thresh = 20;
conn->ifc_max_retx_since_last_ack = MAX_RETR_PACKETS_SINCE_LAST_ACK;
maybe_enable_spin(conn);
if (conn->ifc_settings->es_noprogress_timeout)
conn->ifc_mflags |= MF_NOPROG_TIMEOUT;
return 0;
}
@ -1422,14 +1452,21 @@ lsquic_ietf_full_conn_server_new (struct lsquic_engine_public *enpub,
*/
have_outgoing_ack = 0;
next_packno = ~0ULL;
/* mini conn may drop Init packets, making gaps; don't warn about them: */
conn->ifc_send_ctl.sc_senhist.sh_flags |= SH_GAP_OK;
while ((packet_out = TAILQ_FIRST(&imc->imc_packets_out)))
{
TAILQ_REMOVE(&imc->imc_packets_out, packet_out, po_next);
/* Holes in the sequence signify ACKed or lost packets */
/* Holes in the sequence signify no-longer-relevant Initial packets or
* ACKed or lost packets.
*/
++next_packno;
for ( ; next_packno < packet_out->po_packno; ++next_packno)
{
lsquic_senhist_add(&conn->ifc_send_ctl.sc_senhist, next_packno);
conn->ifc_send_ctl.sc_senhist.sh_warn_thresh = next_packno;
}
packet_out->po_path = CUR_NPATH(conn);
if (imc->imc_sent_packnos & (1ULL << packet_out->po_packno))
@ -1453,6 +1490,11 @@ lsquic_ietf_full_conn_server_new (struct lsquic_engine_public *enpub,
(1 << QUIC_FRAME_ACK);
}
}
conn->ifc_send_ctl.sc_senhist.sh_flags &= ~SH_GAP_OK;
/* ...Yes, that's a bunch of little annoying steps to suppress the gap
* warnings, but it would have been even more annoying (and expensive)
* to add packet renumbering logic to the mini conn.
*/
for (pns = 0; pns < N_PNS; ++pns)
for (i = 0; i < 4; ++i)
@ -4307,10 +4349,7 @@ switch_path_to (struct ietf_full_conn *conn, unsigned char path_id)
conn->ifc_send_flags &= ~(SF_SEND_PATH_RESP << old_path_id);
lsquic_alarmset_unset(&conn->ifc_alset, AL_PATH_CHAL + old_path_id);
if (conn->ifc_flags & IFC_SERVER)
{
memset(&conn->ifc_paths[old_path_id], 0, sizeof(conn->ifc_paths[0]));
conn->ifc_paths[old_path_id].cop_path.np_path_id = old_path_id;
}
wipe_path(conn, old_path_id);
}
@ -5417,6 +5456,24 @@ process_retire_connection_id_frame (struct ietf_full_conn *conn,
return 0;
}
retire_cid(conn, cce, packet_in->pi_received);
if (lconn->cn_cur_cce_idx == cce - lconn->cn_cces)
{
cce = find_cce_by_cid(conn, &packet_in->pi_dcid);
if (cce)
{
LSQ_DEBUGC("current SCID was retired; set current SCID to "
"%"CID_FMT" based on DCID in incoming packet",
CID_BITS(&packet_in->pi_dcid));
cce->cce_flags |= CCE_USED;
lconn->cn_cur_cce_idx = cce - lconn->cn_cces;
}
else
LSQ_WARN("current SCID was retired; no new SCID candidate");
/* This could theoretically happen when zero-length CIDs were
* used. Currently, there should be no way lsquic could get
* into this situation.
*/
}
}
else
LSQ_DEBUG("cannot retire CID seqno=%"PRIu64": not found", seqno);
@ -6521,15 +6578,29 @@ process_incoming_packet_fast (struct ietf_full_conn *conn,
}
static void
set_earliest_idle_alarm (struct ietf_full_conn *conn, lsquic_time_t idle_conn_to)
{
lsquic_time_t exp;
if (conn->ifc_pub.last_prog
&& (assert(conn->ifc_mflags & MF_NOPROG_TIMEOUT),
exp = conn->ifc_pub.last_prog + conn->ifc_enpub->enp_noprog_timeout,
exp < idle_conn_to))
idle_conn_to = exp;
if (idle_conn_to)
lsquic_alarmset_set(&conn->ifc_alset, AL_IDLE, idle_conn_to);
}
static void
ietf_full_conn_ci_packet_in (struct lsquic_conn *lconn,
struct lsquic_packet_in *packet_in)
{
struct ietf_full_conn *conn = (struct ietf_full_conn *) lconn;
if (conn->ifc_idle_to)
lsquic_alarmset_set(&conn->ifc_alset, AL_IDLE,
packet_in->pi_received + conn->ifc_idle_to);
set_earliest_idle_alarm(conn, conn->ifc_idle_to
? packet_in->pi_received + conn->ifc_idle_to : 0);
if (0 == (conn->ifc_flags & IFC_IMMEDIATE_CLOSE_FLAGS))
if (0 != conn->ifc_process_incoming_packet(conn, packet_in))
conn->ifc_flags |= IFC_ERROR;
@ -6646,6 +6717,32 @@ static void (*const send_funcs[N_SEND])(
|SF_SEND_ACK_FREQUENCY\
|SF_SEND_STOP_SENDING)
/* This should be called before lsquic_alarmset_ring_expired() */
static void
maybe_set_noprogress_alarm (struct ietf_full_conn *conn, lsquic_time_t now)
{
lsquic_time_t exp;
if (conn->ifc_mflags & MF_NOPROG_TIMEOUT)
{
if (conn->ifc_pub.last_tick)
{
exp = conn->ifc_pub.last_prog + conn->ifc_enpub->enp_noprog_timeout;
if (!lsquic_alarmset_is_set(&conn->ifc_alset, AL_IDLE)
|| exp < conn->ifc_alset.as_expiry[AL_IDLE])
lsquic_alarmset_set(&conn->ifc_alset, AL_IDLE, exp);
conn->ifc_pub.last_tick = now;
}
else
{
conn->ifc_pub.last_tick = now;
conn->ifc_pub.last_prog = now;
}
}
}
static enum tick_st
ietf_full_conn_ci_tick (struct lsquic_conn *lconn, lsquic_time_t now)
{
@ -6688,6 +6785,8 @@ ietf_full_conn_ci_tick (struct lsquic_conn *lconn, lsquic_time_t now)
conn->ifc_flags &= ~IFC_HAVE_SAVED_ACK;
}
maybe_set_noprogress_alarm(conn, now);
lsquic_send_ctl_tick_in(&conn->ifc_send_ctl, now);
lsquic_send_ctl_set_buffer_stream_packets(&conn->ifc_send_ctl, 1);
CLOSE_IF_NECESSARY();

View file

@ -635,7 +635,7 @@ ietf_mini_conn_ci_is_tickable (struct lsquic_conn *lconn)
if (!(packet_out->po_flags & PO_SENT))
{
packet_size = lsquic_packet_out_total_sz(lconn, packet_out);
return imico_can_send(conn, packet_size + IQUIC_TAG_LEN);
return imico_can_send(conn, packet_size);
}
return 0;
@ -665,15 +665,15 @@ ietf_mini_conn_ci_next_packet_to_send (struct lsquic_conn *lconn, size_t size)
packet_size = lsquic_packet_out_total_sz(lconn, packet_out);
if (size == 0 || packet_size + size <= conn->imc_path.np_pack_size)
{
if (!imico_can_send(conn, packet_size + IQUIC_TAG_LEN))
if (!imico_can_send(conn, packet_size))
{
LSQ_DEBUG("cannot send packet %"PRIu64" of size %zu: client "
"address has not been validated", packet_out->po_packno,
packet_size + IQUIC_TAG_LEN);
packet_size);
return NULL;
}
packet_out->po_flags |= PO_SENT;
conn->imc_bytes_out += packet_size + IQUIC_TAG_LEN;
conn->imc_bytes_out += packet_size;
if (size == 0)
LSQ_DEBUG("packet_to_send: %"PRIu64, packet_out->po_packno);
else
@ -1310,7 +1310,7 @@ ietf_mini_conn_ci_packet_not_sent (struct lsquic_conn *lconn,
packet_out->po_flags &= ~PO_SENT;
packet_size = lsquic_packet_out_total_sz(lconn, packet_out);
conn->imc_bytes_out -= packet_size + IQUIC_TAG_LEN;
conn->imc_bytes_out -= packet_size;
LSQ_DEBUG("%s: packet %"PRIu64" not sent", __func__, packet_out->po_packno);
}
@ -1356,9 +1356,11 @@ imico_handle_losses_and_have_unsent (struct ietf_mini_conn *conn,
{
TAILQ_HEAD(, lsquic_packet_out) lost_packets =
TAILQ_HEAD_INITIALIZER(lost_packets);
const struct lsquic_conn *const lconn = &conn->imc_conn;
lsquic_packet_out_t *packet_out, *next;
lsquic_time_t retx_to = 0;
unsigned n_to_send = 0;
size_t packet_size;
for (packet_out = TAILQ_FIRST(&conn->imc_packets_out); packet_out;
packet_out = next)
@ -1376,8 +1378,11 @@ imico_handle_losses_and_have_unsent (struct ietf_mini_conn *conn,
TAILQ_INSERT_TAIL(&lost_packets, packet_out, po_next);
}
}
else
else if (packet_size = lsquic_packet_out_total_sz(lconn, packet_out),
imico_can_send(conn, packet_size))
++n_to_send;
else
break;
}
conn->imc_hsk_count += !TAILQ_EMPTY(&lost_packets);
@ -1387,7 +1392,11 @@ imico_handle_losses_and_have_unsent (struct ietf_mini_conn *conn,
TAILQ_REMOVE(&lost_packets, packet_out, po_next);
if ((packet_out->po_frame_types & IQUIC_FRAME_RETX_MASK)
&& 0 == imico_repackage_packet(conn, packet_out))
++n_to_send;
{
packet_size = lsquic_packet_out_total_sz(lconn, packet_out);
if (imico_can_send(conn, packet_size))
++n_to_send;
}
else
imico_destroy_packet(conn, packet_out);
}

View file

@ -220,7 +220,8 @@ typedef struct lsquic_packet_out
#if LSQUIC_EXTRA_CHECKS
#define lsquic_packet_out_sent_sz(lconn, p) ( \
__builtin_expect(((p)->po_flags & PO_SENT_SZ), 1) ? \
(assert((p)->po_sent_sz == lsquic_packet_out_total_sz(lconn, p)), \
(assert(((p)->po_flags & PO_HELLO /* Avoid client DCID change */) \
|| (p)->po_sent_sz == lsquic_packet_out_total_sz(lconn, p)), \
(p)->po_sent_sz) : lsquic_packet_out_total_sz(lconn, p))
# else
#define lsquic_packet_out_sent_sz(lconn, p) ( \

View file

@ -363,10 +363,7 @@ lsquic_send_ctl_init (lsquic_send_ctl_t *ctl, struct lsquic_alarmset *alset,
ctl->sc_cached_bpt.stream_id = UINT64_MAX;
#if LSQUIC_EXTRA_CHECKS
ctl->sc_flags |= SC_SANITY_CHECK;
#else
if ((ctl->sc_conn_pub->lconn->cn_flags & (LSCONN_IETF|LSCONN_SERVER))
== LSCONN_IETF)
ctl->sc_flags |= SC_SANITY_CHECK;
LSQ_DEBUG("sanity checks enabled");
#endif
ctl->sc_gap = UINT64_MAX - 1 /* Can't have +1 == 0 */;
if ((ctl->sc_conn_pub->lconn->cn_flags & (LSCONN_IETF|LSCONN_SERVER))
@ -2227,7 +2224,8 @@ lsquic_send_ctl_squeeze_sched (lsquic_send_ctl_t *ctl)
packet_out = next)
{
next = TAILQ_NEXT(packet_out, po_next);
if (packet_out->po_regen_sz < packet_out->po_data_sz)
if (packet_out->po_regen_sz < packet_out->po_data_sz
|| packet_out->po_frame_types == QUIC_FTBIT_PATH_CHALLENGE)
{
if (packet_out->po_flags & PO_ENCRYPTED)
send_ctl_return_enc_data(ctl, packet_out);
@ -2238,7 +2236,7 @@ lsquic_send_ctl_squeeze_sched (lsquic_send_ctl_t *ctl)
/* Log the whole list before we squeeze for the first time */
if (!pre_squeeze_logged++)
LOG_PACKET_Q(&ctl->sc_scheduled_packets,
"unacked packets before squeezing");
"scheduled packets before squeezing");
#endif
send_ctl_sched_remove(ctl, packet_out);
LSQ_DEBUG("Dropping packet %"PRIu64" from scheduled queue",
@ -2255,7 +2253,7 @@ lsquic_send_ctl_squeeze_sched (lsquic_send_ctl_t *ctl)
#ifndef NDEBUG
if (pre_squeeze_logged)
LOG_PACKET_Q(&ctl->sc_scheduled_packets,
"unacked packets after squeezing");
"scheduled packets after squeezing");
else if (ctl->sc_n_scheduled > 0)
LOG_PACKET_Q(&ctl->sc_scheduled_packets, "delayed packets");
#endif

View file

@ -16,11 +16,14 @@
typedef struct lsquic_senhist {
lsquic_packno_t sh_last_sent;
lsquic_packno_t sh_warn_thresh;
enum {
#if !LSQUIC_SENHIST_FATAL
SH_WARNED = 1 << 0, /* Warn once */
#endif
SH_GAP_OK = 1 << 1, /* Before connection is just about to close */
SH_GAP_OK = 1 << 1, /* Before connection is just about to close or
* during mini/full packet handoff.
*/
} sh_flags;
} lsquic_senhist_t;
@ -35,7 +38,8 @@ typedef struct lsquic_senhist {
#if LSQUIC_SENHIST_FATAL
#define lsquic_senhist_add(hist, packno) do { \
if (!((hist)->sh_flags & SH_GAP_OK)) \
if (!((hist)->sh_flags & SH_GAP_OK) \
&& (packno) > (hist)->sh_warn_thresh) \
assert((hist)->sh_last_sent == packno - 1); \
if ((int64_t) (packno) > (int64_t) (hist)->sh_last_sent) \
(hist)->sh_last_sent = packno; \
@ -44,7 +48,8 @@ typedef struct lsquic_senhist {
#define lsquic_senhist_add(hist, packno) do { \
if ((hist)->sh_last_sent != packno - 1) \
{ \
if (!((hist)->sh_flags & (SH_WARNED|SH_GAP_OK))) \
if (!((hist)->sh_flags & (SH_WARNED|SH_GAP_OK)) \
&& (packno) > (hist)->sh_warn_thresh) \
{ \
LSQ_WARN("send history gap %"PRIu64" - %"PRIu64, \
(hist)->sh_last_sent, packno); \

View file

@ -137,7 +137,7 @@ lsquic_sfcw_set_max_recv_off (struct lsquic_sfcw *fc, uint64_t max_recv_off)
}
else
{
LSQ_WARN("flow control violation: received at offset %"PRIu64", "
LSQ_INFO("flow control violation: received at offset %"PRIu64", "
"while flow control receive offset is %"PRIu64,
max_recv_off, fc->sf_recv_off);
return 0;

View file

@ -259,6 +259,26 @@ stream_inside_callback (const lsquic_stream_t *stream)
}
/* This is an approximation. If data is written or read outside of the
* event loop, last_prog will be somewhat out of date, but it's close
* enough for our purposes.
*/
static void
maybe_update_last_progress (struct lsquic_stream *stream)
{
if (stream->conn_pub && !lsquic_stream_is_critical(stream))
{
if (stream->conn_pub->last_prog != stream->conn_pub->last_tick)
LSQ_DEBUG("update last progress to %"PRIu64,
stream->conn_pub->last_tick);
stream->conn_pub->last_prog = stream->conn_pub->last_tick;
#ifndef NDEBUG
stream->sm_last_prog = stream->conn_pub->last_tick;
#endif
}
}
static void
maybe_conn_to_tickable (lsquic_stream_t *stream)
{
@ -1460,6 +1480,8 @@ ssize_t
lsquic_stream_readf (struct lsquic_stream *stream,
size_t (*readf)(void *, const unsigned char *, size_t, int), void *ctx)
{
ssize_t nread;
SM_HISTORY_APPEND(stream, SHE_USER_READ);
if (lsquic_stream_is_reset(stream))
@ -1485,7 +1507,11 @@ lsquic_stream_readf (struct lsquic_stream *stream,
return 0;
}
return stream_readf(stream, readf, ctx);
nread = stream_readf(stream, readf, ctx);
if (nread >= 0)
maybe_update_last_progress(stream);
return nread;
}
@ -2745,6 +2771,9 @@ verify_conn_cap (const struct lsquic_conn_public *conn_pub)
struct lsquic_hash_elem *el;
unsigned n_buffered;
if (conn_pub->wtp_level > 1)
return;
if (!conn_pub->all_streams)
/* TODO: enable this check for unit tests as well */
return;
@ -2760,6 +2789,7 @@ verify_conn_cap (const struct lsquic_conn_public *conn_pub)
assert(n_buffered + conn_pub->stream_frame_bytes
== conn_pub->conn_cap.cc_sent);
LSQ_DEBUG("%s: cc_sent: %"PRIu64, __func__, conn_pub->conn_cap.cc_sent);
}
@ -3056,6 +3086,10 @@ stream_write_to_packets (lsquic_stream_t *stream, struct lsquic_reader *reader,
.fgc_nread_from_reader = 0,
};
#if LSQUIC_EXTRA_CHECKS
if (stream->conn_pub)
++stream->conn_pub->wtp_level;
#endif
use_framing = (stream->sm_bflags & (SMBF_IETF|SMBF_USE_HEADERS))
== (SMBF_IETF|SMBF_USE_HEADERS);
if (use_framing)
@ -3079,7 +3113,10 @@ stream_write_to_packets (lsquic_stream_t *stream, struct lsquic_reader *reader,
{
case SWTP_OK:
if (!seen_ok++)
{
maybe_conn_to_tickable_if_writeable(stream, 0);
maybe_update_last_progress(stream);
}
if (fg_ctx.fgc_fin(&fg_ctx))
{
if (use_framing && seen_ok)
@ -3097,7 +3134,7 @@ stream_write_to_packets (lsquic_stream_t *stream, struct lsquic_reader *reader,
default:
abort_connection(stream);
stream->stream_flags &= ~STREAM_LAST_WRITE_OK;
return -1;
goto err;
}
}
@ -3113,7 +3150,7 @@ stream_write_to_packets (lsquic_stream_t *stream, struct lsquic_reader *reader,
{
nw = save_to_buffer(stream, reader, size);
if (nw < 0)
return -1;
goto err;
fg_ctx.fgc_nread_from_reader += nw; /* Make this cleaner? */
}
}
@ -3129,7 +3166,18 @@ stream_write_to_packets (lsquic_stream_t *stream, struct lsquic_reader *reader,
maybe_mark_as_blocked(stream);
end:
#if LSQUIC_EXTRA_CHECKS
if (stream->conn_pub)
--stream->conn_pub->wtp_level;
#endif
return fg_ctx.fgc_nread_from_reader;
err:
#if LSQUIC_EXTRA_CHECKS
if (stream->conn_pub)
--stream->conn_pub->wtp_level;
#endif
return -1;
}
@ -4056,6 +4104,7 @@ lsquic_stream_get_hset (struct lsquic_stream *stream)
stream->stream_flags |= STREAM_FIN_REACHED;
SM_HISTORY_APPEND(stream, SHE_REACH_FIN);
}
maybe_update_last_progress(stream);
LSQ_DEBUG("return header set");
return hset;
}
@ -4347,12 +4396,15 @@ hq_read (void *ctx, const unsigned char *buf, size_t sz, int fin)
LSQ_INFO("FIN at unexpected place in filter; state: %u",
filter->hqfi_state);
filter->hqfi_flags |= HQFI_FLAG_ERROR;
/* From [draft-ietf-quic-http-16] Section 3.1:
* When a stream terminates cleanly, if the last frame on
* the stream was truncated, this MUST be treated as a connection error
* (see HTTP_MALFORMED_FRAME in Section 8.1).
/* From [draft-ietf-quic-http-28] Section 7.1:
" When a stream terminates cleanly, if the last frame on the stream was
" truncated, this MUST be treated as a connection error (Section 8) of
" type H3_FRAME_ERROR. Streams which terminate abruptly may be reset
" at any point in a frame.
*/
abort_connection(stream);
lconn = stream->conn_pub->lconn;
lconn->cn_if->ci_abort_error(lconn, 1, HEC_FRAME_ERROR,
"last HTTP/3 frame on stream %"PRIu64" was truncated", stream->id);
}
return p - buf;

View file

@ -317,6 +317,11 @@ struct lsquic_stream
uint64_t sm_last_frame_off;
#ifndef NDEBUG
/* Last time stream made progress */
lsquic_time_t sm_last_prog;
#endif
/* Content length specified in incoming `content-length' header field.
* Used to verify size of DATA frames.
*/

@ -1 +1 @@
Subproject commit b577d56964e443972adb38ec56706181846cc47f
Subproject commit bd5d58987e0e88d7c1b676f83624528926fb423a