Re: qlog, AckFrame, and ack_delay

Marten Seemann <martenseemann@gmail.com> Tue, 14 November 2023 10:19 UTC

Return-Path: <martenseemann@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 C1EB4C14CE4B for <quic@ietfa.amsl.com>; Tue, 14 Nov 2023 02:19:48 -0800 (PST)
X-Virus-Scanned: amavisd-new at amsl.com
X-Spam-Flag: NO
X-Spam-Score: -7.104
X-Spam-Level:
X-Spam-Status: No, score=-7.104 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_FROM=0.001, HTML_MESSAGE=0.001, RCVD_IN_DNSWL_HI=-5, 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 nZruTw-9EDYL for <quic@ietfa.amsl.com>; Tue, 14 Nov 2023 02:19:47 -0800 (PST)
Received: from mail-ej1-x632.google.com (mail-ej1-x632.google.com [IPv6:2a00:1450:4864:20::632]) (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 E0005C14CE52 for <quic@ietf.org>; Tue, 14 Nov 2023 02:19:42 -0800 (PST)
Received: by mail-ej1-x632.google.com with SMTP id a640c23a62f3a-991c786369cso819131966b.1 for <quic@ietf.org>; Tue, 14 Nov 2023 02:19:42 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20230601; t=1699957180; x=1700561980; 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=EMfer8/QTlABzLhLKCX6lTAtsJYWJs+eDo+w58EV9mE=; b=eBxbedusW+nd20ad54Gw8ZlEgqljHCAEzrXk6hU8S04OMjl+dAbLzjVcEtqg9yjk98 h63/tMKpNaex6AaSlg3iNmCZtshdK4R8xrykYqvXE0uHXVeME/iO6WZn5w3ANexf+QRU z028PxnZy3KXzj38IAAAK4WwRxe8kaOWRHgnTqNsBb5VAcI54vkVZRtYSDxQkQC/oSzI TLZ3rbDUFdLkqzGUCUSz1PQnae/CST3LkF837RE0XUycg9ZPs6Ijxbfe+m5iW6EqmiHr Hv50Ln/MNGPiRd/hwXGzxHWfTe3z1wd4SYWpf8sFyVCHJ3RJXB1qJiGoySE0rnBMv1sl VIQA==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1699957180; x=1700561980; 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=EMfer8/QTlABzLhLKCX6lTAtsJYWJs+eDo+w58EV9mE=; b=U59k4VM4lHVA+4BJPDJNEi4ENzdimOSTOafFNL4Uc5upp4fRwqa/Oldjq4y5kjZcEo /4gEi91xx2hRdaH/9avyDr+gB1JwWkFHhMKSZVPA0ftUj0+TMv52incOGLrULZHj7Y76 X2Pacd6Yb//KlOALH7l31jNyCY3b1o6O5+eoeq/AjGVQzY5PhrsmkmjYj6JU8/CRCEZe vEnI6xsYd1IZSJmhX+79nBx7ovERCyrpTuoptejzsgcSoBwnr4vLuDFXhkV9Z/C5Wa02 5cOuv/MVFuDhjXh16lzJD/u4YzyrEpGPMlbY++7V/Y44lm0LMubO62VJIdp5EoVuISRP AkjQ==
X-Gm-Message-State: AOJu0YzM5ECYTnWHRBG5Dws1DqMcFENU/oCBIMliTzzUEgYuZNOjz4Ay 7ss6Qbrv5WVgtu2s+QVOqzDjomhRxjdw27XJ+Hw=
X-Google-Smtp-Source: AGHT+IEqnmxOtGYELEjTkPD6N1wS6LCk4stUQ2QJGTRZdC5K9rdPtYTyskm35CBM6ppCujFlVD8PwxsIgMqdNYHxcMQ=
X-Received: by 2002:a17:907:770d:b0:9ae:5120:5147 with SMTP id kw13-20020a170907770d00b009ae51205147mr5232923ejc.38.1699957179971; Tue, 14 Nov 2023 02:19:39 -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> <CAOoMnrg35P2F5qm_5Xqwr0DE4uFQ8OVKSY3atCJ_MTCV_VkhbQ@mail.gmail.com>
In-Reply-To: <CAOoMnrg35P2F5qm_5Xqwr0DE4uFQ8OVKSY3atCJ_MTCV_VkhbQ@mail.gmail.com>
From: Marten Seemann <martenseemann@gmail.com>
Date: Tue, 14 Nov 2023 10:19:28 +0000
Message-ID: <CAOYVs2o6Ks5CrrrrHew06szbdSuiDqa=RU5-zVUy4-rkAE6AbQ@mail.gmail.com>
Subject: Re: qlog, AckFrame, and ack_delay
To: Robin Marx <marx.robin@gmail.com>
Cc: Damien Neil <dneil=40google.com@dmarc.ietf.org>, Lucas Pardue <lucaspardue.24.7@gmail.com>, QUIC WG <quic@ietf.org>
Content-Type: multipart/alternative; boundary="000000000000d87b0c060a1a1f94"
Archived-At: <https://mailarchive.ietf.org/arch/msg/quic/WBB4A0gU9Wu1Mt9-qrXwsnoZ_Bg>
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: Tue, 14 Nov 2023 10:19:48 -0000

I had always assumed that RawInfo only applied to the payload of the STREAM
and DATAGRAM frame. Looking at the definition of RawInfo, it looks like my
assumption was likely wrong :)

While I can see potential value in logging the data sent in STREAM /
DATAGRAM frames, I don't think there's anything useful that can be learned
from logging the wire representation of the frame. The only conceivable
piece of information one could learn from that is how many bytes were used
for encoding the integer values. I don't see how this would be useful.
Logging the entire frame means that a qlog consumer who is interested in
the payload of these frames now needs to implement a QUIC frame parser.

Instead of adding a RawInfo field to all frames, I'd therefore like to
propose to change the definition of STREAM and DATAGRAM frames, such that
we only enable logging of the payload of these frames.

On Tue, 14 Nov 2023 at 10:08, Robin Marx <marx.robin@gmail.com> wrote:

> Hello all,
>
> Sorry for the late reply from my end; I had some troubles posting to the
> list and my original reply got lost in moderation.
>
> I can appreciate both sides of the argument here.
> Originally I tended more towards Damien's suggestion and opened a PR for
> it at https://github.com/quicwg/qlog/pull/337.
> However, I think Marten and Lucas make good arguments for things like
> HTTP/3 header compression and packet number encoding needing "global"
> persistent state to decode.
> I also feel the unscaled ack value isn't really useful in tooling (which
> is the main use case for qlog).
>
> I also follow Lucas' argument that a good fallback option would be to log
> the raw bytes using the "? raw: RawInfo" field.
> However, for this I see that we don't have this explicitly defined for all
> possible frames (including AckFrame) only on some (like StreamFrame or
> UnknownFrame).
> As such, if this option is chosen, we should add the explicit "raw" field
> to all (most?) frames as well imo.
> I'm guessing that would also meet Marten's approval?
>
> With best regards,
> Robin
>
>
> On Fri, Nov 10, 2023 at 6:50 PM Damien Neil <dneil=
> 40google.com@dmarc.ietf.org> 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
>>>>>>
>>>>>
>
> --
> Marx Robin
> +32 (0)497 72 86 94
>