Re: qlog, AckFrame, and ack_delay

Lucas Pardue <lucaspardue.24.7@gmail.com> Fri, 10 November 2023 18:06 UTC

Return-Path: <lucaspardue.24.7@gmail.com>
X-Original-To: quic@ietfa.amsl.com
Delivered-To: quic@ietfa.amsl.com
Received: from localhost (localhost [127.0.0.1]) by ietfa.amsl.com (Postfix) with ESMTP id B670CC18E54E for <quic@ietfa.amsl.com>; Fri, 10 Nov 2023 10:06:42 -0800 (PST)
X-Virus-Scanned: amavisd-new at amsl.com
X-Spam-Flag: NO
X-Spam-Score: -1.854
X-Spam-Level:
X-Spam-Status: No, score=-1.854 tagged_above=-999 required=5 tests=[BAYES_00=-1.9, DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, FREEMAIL_ENVFROM_END_DIGIT=0.25, FREEMAIL_FROM=0.001, HTML_MESSAGE=0.001, RCVD_IN_ZEN_BLOCKED_OPENDNS=0.001, SPF_HELO_NONE=0.001, SPF_PASS=-0.001, T_SCC_BODY_TEXT_LINE=-0.01, URIBL_BLOCKED=0.001, URIBL_DBL_BLOCKED_OPENDNS=0.001, URIBL_ZEN_BLOCKED_OPENDNS=0.001] autolearn=unavailable autolearn_force=no
Authentication-Results: ietfa.amsl.com (amavisd-new); dkim=pass (2048-bit key) header.d=gmail.com
Received: from mail.ietf.org ([50.223.129.194]) by localhost (ietfa.amsl.com [127.0.0.1]) (amavisd-new, port 10024) with ESMTP id JPog616rX7kG for <quic@ietfa.amsl.com>; Fri, 10 Nov 2023 10:06:38 -0800 (PST)
Received: from mail-oa1-x2a.google.com (mail-oa1-x2a.google.com [IPv6:2001:4860:4864:20::2a]) (using TLSv1.3 with cipher TLS_AES_128_GCM_SHA256 (128/128 bits) key-exchange X25519 server-signature RSA-PSS (2048 bits) server-digest SHA256) (No client certificate requested) by ietfa.amsl.com (Postfix) with ESMTPS id E8054C18E558 for <quic@ietf.org>; Fri, 10 Nov 2023 10:06:38 -0800 (PST)
Received: by mail-oa1-x2a.google.com with SMTP id 586e51a60fabf-1f4b03656caso422512fac.0 for <quic@ietf.org>; Fri, 10 Nov 2023 10:06:38 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20230601; t=1699639597; x=1700244397; darn=ietf.org; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:from:to:cc:subject:date:message-id:reply-to; bh=yPcCm2YyFPS+wRQUCRGxvjoeVuZnliZQYQrV7DkPQIQ=; b=EWrgzTYcwJjV73rjaE4F6RVozbnswagVLDgZ7fViJaqONnSdXX1MJLYSphtVoCuLNV BQu72xq54p7OyPUplWFIr7KNAolfjhlYHTumcOtyWlwK9tUFdTRu1N/wOqSjWqRW222v 0JHos0wUst0QKXP+c7XnJ6DbBJtkwYUAbus4PNwJvFjhv46LeGZ+C5vad5CRyNNCSdN1 czaYM7f0cAxlWyNHn+S6O2TKNdCWsFvpJaiOz0c6WKqrqoYYYfUkQ3PZYLCDwc+zO7Hu X3CM4fG6lJoRk6XsGDEhSR96ZvuIyijp4Ah7/FGkYgrSAoooasV2M2J7NRFOsPebRVLI jrAQ==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1699639597; x=1700244397; h=cc:to:subject:message-id:date:from:in-reply-to:references :mime-version:x-gm-message-state:from:to:cc:subject:date:message-id :reply-to; bh=yPcCm2YyFPS+wRQUCRGxvjoeVuZnliZQYQrV7DkPQIQ=; b=KpPJrSV+vLG2dBcgeRdbYo3wk9EQ9Id2El4lTemk0+sx6R95zaTp6FxXRV1JR6NcNt WfkjVpURfBGryHeiFA1DpNXWzdd0+56kDxRcAezo4tHiqzAk0bHEKuPwKATEMruO4UVT QmBsELOijjvCsCF2sEUazqrN8WRJwD0X9JbMil89jP/As6NUpy6Nb552Nwcv6XUumDHe AIc3AJXuINHgw8RNROMSDB/TlWsuwunca8fI9n7ks9w3OpM5JCXUuefxEF6qJ/d1bFCi +pj3RonhYqO7t/HPLmRbN83SY07IprHKsLWIg17lXLPsBpTupQnnwb/qqXk2Xv3mZ2yy 2wag==
X-Gm-Message-State: AOJu0YzdS4y/aryeyi58jVpXlmcpIfjnqTsTLab5rCZEiDKwrmERg0r7 AktRuC0Bch4h3G5Aevhcgx5B1IVKuB8jqyqgDIg=
X-Google-Smtp-Source: AGHT+IF+izcpd6mszmNusxAcuU4aDlCHWyzCoqswUfJf2toE1EHmxlCXD7aFf9PwAXGJFiqlcDUXqKZTjfWt7Pvx8jU=
X-Received: by 2002:a05:6870:10cb:b0:1f0:36ab:2886 with SMTP id 11-20020a05687010cb00b001f036ab2886mr8802197oar.41.1699639597496; Fri, 10 Nov 2023 10:06:37 -0800 (PST)
MIME-Version: 1.0
References: <CAGgfL4tDDb7jZ-e-_STZ8SFPESyuPtqfFesQZOjzX_5i0XpAdw@mail.gmail.com> <CAOYVs2p2Z1JMa97uXF0SYYzsw_AOFP0-G9R+PVfeMwRw46Gw-w@mail.gmail.com> <CAGgfL4u=T-f=Uft=0-cLN9Jte4RETwYVq1UsmDVUER5geDnMiw@mail.gmail.com> <CALGR9oZU7ppYX8WDob_NXjy2exn5rNT4zLojKtaqP7b2P3gTag@mail.gmail.com> <CAGgfL4vrkSgCbOtPOFZ0c6XEKSe5JPxApbKh5KkMHP0VZGPAZg@mail.gmail.com>
In-Reply-To: <CAGgfL4vrkSgCbOtPOFZ0c6XEKSe5JPxApbKh5KkMHP0VZGPAZg@mail.gmail.com>
From: Lucas Pardue <lucaspardue.24.7@gmail.com>
Date: Fri, 10 Nov 2023 19:06:25 +0100
Message-ID: <CALGR9obic1XRHaESNj5AA5-OYpqB=AsbBeO_fHZfUf4TN2ftuA@mail.gmail.com>
Subject: Re: qlog, AckFrame, and ack_delay
To: Damien Neil <dneil@google.com>
Cc: Damien Neil <dneil=40google.com@dmarc.ietf.org>, Marten Seemann <martenseemann@gmail.com>, QUIC WG <quic@ietf.org>
Content-Type: multipart/alternative; boundary="0000000000007480680609d02eb3"
Archived-At: <https://mailarchive.ietf.org/arch/msg/quic/oLKG3He6gV4QLI360bvsA2Z5FNw>
X-BeenThere: quic@ietf.org
X-Mailman-Version: 2.1.39
Precedence: list
List-Id: Main mailing list of the IETF QUIC working group <quic.ietf.org>
List-Unsubscribe: <https://www.ietf.org/mailman/options/quic>, <mailto:quic-request@ietf.org?subject=unsubscribe>
List-Archive: <https://mailarchive.ietf.org/arch/browse/quic/>
List-Post: <mailto:quic@ietf.org>
List-Help: <mailto:quic-request@ietf.org?subject=help>
List-Subscribe: <https://www.ietf.org/mailman/listinfo/quic>, <mailto:quic-request@ietf.org?subject=subscribe>
X-List-Received-Date: Fri, 10 Nov 2023 18:06:42 -0000

Thanks.

The other examples that co?e to mind is in pcap dissection of HTTP/2 and
HTTP/3. The header conpression is stateful and requires access to the full
capture from start to finish (to cover all dynamic table updates). The
fallback mode for those is to display the raw bytes.

In qlog, each PacketReceived event has a `raw` field that can do the
equivalent. It seems possible that that tooling could detect omission
`ack_delay` and prescense of `raw` as a signal to decode the value of the
field as received. The downside is that the full packet bytes are recorded.
A compromise might be to make the raw bytes of frames available, so that
applications can apply finer granularity e.g., log control frame data but
omit application frame data that is more sensitive.

On Fri, 10 Nov 2023, 18:50 Damien Neil, <dneil@google.com> wrote:

> I believe the ACK Delay field is unique in the QUIC wire protocol in being
> a field which can't be interpreted without information from a separate
> protocol layer. I don't think this change leads to anything else.
>
> More precisely: Viewed as an integer, ACK Delay can be interpreted by
> considering the ACK frame alone. Viewed as a duration, it requires
> additional information exchanged in the TLS handshake. ACK Delay is the
> only field I know of which has this duality.
>
> I can write a function which takes a QUIC packet payload and outputs a
> list of qlog $QuicFrames, with the sole exception of the ACK Delay field
> which requires access to the ack_delay_exponent. And as the
> ack_delay_exponent is not known early in the handshake, it's currently
> impossible to fully log early ACK frames. (Probably the right choice under
> the current design is to not emit the ack_delay field in this case.)
>
> On Fri, Nov 10, 2023 at 9:20 AM Lucas Pardue <lucaspardue.24.7@gmail.com>
> wrote:
>
>> These use cases seem like they are more general than just one field in
>> one frame type.
>>
>> I don't want to commit to doing 1 thing if it's the start of a string of
>> work that updates many other events.
>>
>> Would you be willing to survey all current events (modulo qpack, which we
>> are removing) in order understand the full scope of change?
>>
>> Cheers
>> Lucas
>>
>> On Fri, 10 Nov 2023, 17:31 Damien Neil, <dneil=
>> 40google.com@dmarc.ietf.org> wrote:
>>
>>> Consider an endpoint processing an ACK frame in an Initial packet
>>> received before transport parameters have been received. This can happen
>>> when, for example, a client's Initial CRYPTO flight is too large to fit in
>>> a single datagram; the server will send an ACK for the first Initial packet
>>> before it has the ability to send transport parameters in the Handshake
>>> flight. Or even in the case where the client Initial CRYPTO flight fits in
>>> one datagram, the server may respond with an ACK in an Initial packet prior
>>> to sending a Handshake packet.
>>>
>>> In this case, the client is processing an ACK frame that may contain a
>>> non-zero ACK Delay value, but has no ability to interpret it because it
>>> doesn't know the peer's ack_delay_exponent. I forget whether it's permitted
>>> for an endpoint to send a non-zero ACK Delay in an Initial packet, but even
>>> if it isn't, the recipient may want to log the value.
>>>
>>> Or one could imagine a tool which converts a pcap packet capture to a
>>> qlog file; in this case, the tool may have access to a key log to permit it
>>> to decrypt packets, but may be processing a section of the log that does
>>> not include the handshake.
>>>
>>> On Fri, Nov 10, 2023 at 12:48 AM Marten Seemann <martenseemann@gmail.com>
>>> wrote:
>>>
>>>> There's a tradeoff here: Giving writers of qlog files more flexibility
>>>> comes at a cost to consumers of qlog files, who now need to support
>>>> multiple representations. There's a lot of value in having only a single
>>>> way to log something.
>>>>
>>>> I'm not sure the proposal for unscaled_ack_delay strikes the right
>>>> balance here. For a consumer of a qlog file, I can't think of a single
>>>> scenario where the unscaled_ack_delay would provide any advantage over the
>>>> actual value, so introducing this option would purely to make the writer's
>>>> life easier. And I'm struggling to see why logging the ack_delay would
>>>> place a big burden on the writer, since a QUIC stack will need to decode
>>>> this field at some point anyway.
>>>>
>>>> On Thu, 9 Nov 2023 at 22:44, Damien Neil <dneil=
>>>> 40google.com@dmarc.ietf.org> wrote:
>>>>
>>>>> The qlog AckFrame type includes the ack delay as a float32 number of
>>>>> milliseconds:
>>>>>
>>>>> AckFrame = {
>>>>>     frame_type: "ack"
>>>>>
>>>>>     ; in ms
>>>>>     ? ack_delay: float32
>>>>>     ; ...
>>>>> }
>>>>>
>>>>>
>>>>> https://www.ietf.org/archive/id/draft-ietf-quic-qlog-quic-events-06.html#section-8.12.3
>>>>>
>>>>> Given a serialized ack frame, determining the delay as a duration
>>>>> requires knowing the ack_delay_exponent. In some cases, the logging
>>>>> endpoint may not have this available (if receiving an ack before transport
>>>>> parameters have been received). Even when available, it may not be easily
>>>>> accessible at the point of logging. For example, in my own implementation,
>>>>> I'd like to be able to convert a packet payload to a series of qlog event
>>>>> frames without needing to reference persistent connection state.
>>>>>
>>>>> I think there should be an alternative to log the raw value of the ACK
>>>>> Delay field:
>>>>>
>>>>> AckFrame = {
>>>>>     frame_type: "ack"
>>>>>
>>>>>     ; in ms
>>>>>     ? ack_delay: float32
>>>>>
>>>>>     ; integer value of the ACK Delay field, not scaled by the
>>>>> ack_delay_exponent
>>>>>     ? unscaled_ack_delay: uint64
>>>>>
>>>>>     ; ...
>>>>> }
>>>>>
>>>>> - Damien
>>>>>
>>>>