Re: qlog, AckFrame, and ack_delay

[Damien Neil <[e-mail]>]

I agree with Marten that logging the raw frame isn't a great option. You
don't want to have to stick a frame parser in every qlog consumer.

I'd still like to know how a producer is supposed to log ack_delay prior to
knowing the peer's max_ack_delay parameter. Are producers just expected to
not log the ACK Delay in that case? That seems unfortunate; the value can't
be used, of course, but that's not a reason not to log it for debugging.

On Tue, Nov 14, 2023 at 2:19 AM Marten Seemann <[e-mail]>
wrote:

> 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 <[e-mail]> 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=
>> [e-mail]> 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 <[e-mail]>
>>> 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=
>>>> [e-mail]> 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 <
>>>>> [e-mail]> 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=
>>>>>> [e-mail]> 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
>> [phone] <+32%20497%2072%2086%2094>
>>
>