Re: qlog, AckFrame, and ack_delay

Marten Seemann <martenseemann@gmail.com> Fri, 10 November 2023 17:42 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 970D1C18E1A4 for <quic@ietfa.amsl.com>; Fri, 10 Nov 2023 09:42:51 -0800 (PST)
X-Virus-Scanned: amavisd-new at amsl.com
X-Spam-Flag: NO
X-Spam-Score: -2.104
X-Spam-Level:
X-Spam-Status: No, score=-2.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_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 a4YlHBNlNQmV for <quic@ietfa.amsl.com>; Fri, 10 Nov 2023 09:42:47 -0800 (PST)
Received: from mail-ed1-x531.google.com (mail-ed1-x531.google.com [IPv6:2a00:1450:4864:20::531]) (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 F04A4C18E1AA for <quic@ietf.org>; Fri, 10 Nov 2023 09:42:46 -0800 (PST)
Received: by mail-ed1-x531.google.com with SMTP id 4fb4d7f45d1cf-54394328f65so3744382a12.3 for <quic@ietf.org>; Fri, 10 Nov 2023 09:42:46 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20230601; t=1699638165; x=1700242965; 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=TBJZjqXhcen4FkITKQQMqQ3CYycavKRZpXQ2Onxt6to=; b=bj1CU70yfvbQ3oxdpdL5j4DEGS5UmU38nUXvDUEFwsjmhuAxvib/U/Kan4+ljC2ojT jISzc/CXbI5ZhUZ+h6lQu3j0joxY1ciGlB0TXxq2P0xSWexFwwfW4dSWQ4l2eJhTNGUJ 1DJooWnXS1NTk5FDGu6JVqe873YOcQPW8pum0+FyEF479dxLiUdmi66YLb1VnT0lFZ39 s1jO1rQXhAw3HsRxNRCuF71vvw6e7rpH2RxpWa64iJ1en7EgDABFfCKrPK7GiGhk25A8 eGToIBoozk5pnSTgnSmrcBMNybb/BqN0k35BpkKH+6dT0KOm0W9EQ/yrf6yEDtWD+hQU 1TTw==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20230601; t=1699638165; x=1700242965; 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=TBJZjqXhcen4FkITKQQMqQ3CYycavKRZpXQ2Onxt6to=; b=D3hCWkcIbYe/6b+pJOo52Ui/FtOsB3hGs/spMJL102dTL8LtDcLh4TUU41bC/u75lj +RLO53xilny11rHY4uKJGJz2NAOrcc4vYKdOjsSr5ll6SE2NfC/LsiGa25eMHml0CjmX yPNfzZXOeWs/6YYzIQ1apyaKK8DfCk5NpVmg8pNwfjGBeBzo4Wc/pY10XYDbJCjQj/9C W2Wi9Qrv/IF5SrfA0SYwzjRpUzR7c19LC0vtPfKOKQnYri/+QOlDIk5FhA1Le7/Ksi0q T36JjE7p3FdPv/gd3SBIMF9Gw3UqO7sAFr8uzwKg9MYmzP4XQXcRdHt9P1UNMagxWddd aR7Q==
X-Gm-Message-State: AOJu0YyRfp1X933rRCA/kqf+Cj7+K57OXSXMkoNnEcRgMMp6nlWlvS2J N6lfmiIpEBDfEDEN8ZCCBHhKUwq1oEutx7lhyQ4=
X-Google-Smtp-Source: AGHT+IEqyblhEE3BC11rlVSRPJgsF9goGAhWbboCytwkP1ixw7Arih0FCO+MyndZfmqAr/Sm8ruM+Oon5/9RRIdxj0E=
X-Received: by 2002:a50:fc09:0:b0:544:98ad:8e99 with SMTP id i9-20020a50fc09000000b0054498ad8e99mr28781edr.40.1699638164895; Fri, 10 Nov 2023 09:42:44 -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>
In-Reply-To: <CAGgfL4u=T-f=Uft=0-cLN9Jte4RETwYVq1UsmDVUER5geDnMiw@mail.gmail.com>
From: Marten Seemann <martenseemann@gmail.com>
Date: Fri, 10 Nov 2023 18:42:33 +0100
Message-ID: <CAOYVs2o0RRMR=0mSw1MtKA4--XL8pQfmru+S2dqoVqMC3__cDA@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>, quic@ietf.org
Content-Type: multipart/alternative; boundary="00000000000010ba170609cfd949"
Archived-At: <https://mailarchive.ietf.org/arch/msg/quic/mXttNj3bVJdPqj5sbBZSns-PcMA>
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 17:42:51 -0000

We discussed that in a separate thread on this list. If I remember
correctly, the outcome of this discussion was inconclusive. Regardless of
the outcome, qlog is the wrong place to fix the problem: Every QUIC stack
will need to scale the ACK delay value at some point (or ignore it and set
it to 0), and that's the value that should be qlogged.

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

A tool that converts a pcap will need access to connection state anyway.
For example, the packet number is compressed, and the generation of the key
phase is never transmitted in full.

On Fri, 10 Nov 2023 at 17:31, Damien Neil <dneil@google.com> 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
>>>
>>