Re: qlog, AckFrame, and ack_delay

Damien Neil <dneil@google.com> Fri, 10 November 2023 16:31 UTC

Return-Path: <dneil@google.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 2B410C17DBF6 for <quic@ietfa.amsl.com>; Fri, 10 Nov 2023 08:31:09 -0800 (PST)
X-Virus-Scanned: amavisd-new at amsl.com
X-Spam-Flag: NO
X-Spam-Score: -17.605
X-Spam-Level:
X-Spam-Status: No, score=-17.605 tagged_above=-999 required=5 tests=[BAYES_00=-1.9, DKIMWL_WL_MED=-0.001, DKIM_SIGNED=0.1, DKIM_VALID=-0.1, DKIM_VALID_AU=-0.1, DKIM_VALID_EF=-0.1, ENV_AND_HDR_SPF_MATCH=-0.5, HTML_MESSAGE=0.001, RCVD_IN_DNSWL_BLOCKED=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, USER_IN_DEF_DKIM_WL=-7.5, USER_IN_DEF_SPF_WL=-7.5] autolearn=ham autolearn_force=no
Authentication-Results: ietfa.amsl.com (amavisd-new); dkim=pass (2048-bit key) header.d=google.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 TZUK6AAWB3bz for <quic@ietfa.amsl.com>; Fri, 10 Nov 2023 08:31:08 -0800 (PST)
Received: from mail-ej1-x634.google.com (mail-ej1-x634.google.com [IPv6:2a00:1450:4864:20::634]) (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 50044C1705ED for <quic@ietf.org>; Fri, 10 Nov 2023 08:31:08 -0800 (PST)
Received: by mail-ej1-x634.google.com with SMTP id a640c23a62f3a-9ae2cc4d17eso375292766b.1 for <quic@ietf.org>; Fri, 10 Nov 2023 08:31:08 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=google.com; s=20230601; t=1699633867; x=1700238667; 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=SxCsMHWUwujqB45rgJjIDg53LFBo5JNYZVkZHWxHMP4=; b=MOBdmD7GI+WySqo+zwlQx43Gl14X5B/0BH9ek0ZeVqp3S42I9y8EdnvTmZctvH+Y6+ J+HKhebptUlcaaN9Ph1PzqMHiK4ulSutmlStvyVkqAOa2c6ChcGxyfo2LhU7t8wfD1Tq QmYlh/gZUxGM9KVX11r7a38Ac78Pg+IzwTsEvN20nI+sBoYj77BCoe2OGzfeb8vh/rq6 kGateWvPqEAf7/AF3+DIiByBxE22UoCuEhu4njyscOt6x3/NiUBuXCyNrNPZtR5+cylD 5U5r2oqntFNGAA7SoY8HNim3N3A47w3eO3q3OEe4A6mPshZ8z7dJR3BwJ2lFz14qTXk6 R9qg==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1699633867; x=1700238667; 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=SxCsMHWUwujqB45rgJjIDg53LFBo5JNYZVkZHWxHMP4=; b=oCTeWsclUPW0of6txeIK4OKZc9HnJM3CD0veQ6WQ+Xw3hdJWA97TF1xeHxbnagHmbk JcK4k11FSlXLfVNi3lv35WJ/KPO86bpXIYmQ+MGcwMy/4iGs+rRgn2bYFmiTPAH7RK0b 1C9uuUv01H62rH8DZdLA06+C64abpP4mMVeoG/TUfmEnj5x2n8Q4TtYa5W1Mik68IQx6 x/OujmCPCOKorMbM7IlvVuVntmpxE7JZ3rMM4AwLERecd+kI0pPIULhCab5dX/dUphmx QEZqBh1nWXPxAO9f1oIPmBxz0PYAr/fLpD/m+qJbLvPruxDIAob0OWwC8pwlFEANAQ3f mo7Q==
X-Gm-Message-State: AOJu0YygUxmZkhy8JF41tClrkxHxLPwV898kKtR8g0iDTz+V8cvNcV4H JiZOqRmR5voH4vv0diaYueioA9aQYQBWJvB0fflPJA==
X-Google-Smtp-Source: AGHT+IF4snAoxVbuWtmqZELzyF7nmOnJFC0qHvhMXbYvZTcNAeRXxfk1V7446RldiUGprz/w2roE47h0FNxnrTIN3g0=
X-Received: by 2002:a17:907:6e86:b0:9dd:6664:1a3a with SMTP id sh6-20020a1709076e8600b009dd66641a3amr7159898ejc.51.1699633866506; Fri, 10 Nov 2023 08:31:06 -0800 (PST)
MIME-Version: 1.0
References: <CAGgfL4tDDb7jZ-e-_STZ8SFPESyuPtqfFesQZOjzX_5i0XpAdw@mail.gmail.com> <CAOYVs2p2Z1JMa97uXF0SYYzsw_AOFP0-G9R+PVfeMwRw46Gw-w@mail.gmail.com>
In-Reply-To: <CAOYVs2p2Z1JMa97uXF0SYYzsw_AOFP0-G9R+PVfeMwRw46Gw-w@mail.gmail.com>
From: Damien Neil <dneil@google.com>
Date: Fri, 10 Nov 2023 08:30:52 -0800
Message-ID: <CAGgfL4u=T-f=Uft=0-cLN9Jte4RETwYVq1UsmDVUER5geDnMiw@mail.gmail.com>
Subject: Re: qlog, AckFrame, and ack_delay
To: Marten Seemann <martenseemann@gmail.com>
Cc: Damien Neil <dneil=40google.com@dmarc.ietf.org>, quic@ietf.org
Content-Type: multipart/alternative; boundary="000000000000dd52840609ced83d"
Archived-At: <https://mailarchive.ietf.org/arch/msg/quic/GFX3RQNW2j2GgwRYLOZRkY576ZU>
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 16:31:09 -0000

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
>>
>