Re: [PATCH v2 2/2] connect, protocol: log negotiated protocol version

From: "Ævar Arnfjörð Bjarmason" <avarab@gmail.com>
To: Josh Steadmon <steadmon@google.com>
Cc: git@vger.kernel.org, gitster@pobox.com, me@ttaylorr.com
Subject: Re: [PATCH v2 2/2] connect, protocol: log negotiated protocol version
Date: Thu, 05 Aug 2021 01:40:51 +0200	[thread overview]
Message-ID: <87a6lwn52u.fsf@evledraar.gmail.com> (raw)
In-Reply-To: <d138b2615c1af288627b9a2f8f7dd3d2fed184d7.1628115065.git.steadmon@google.com>

On Wed, Aug 04 2021, Josh Steadmon wrote:

> It is useful for performance monitoring and debugging purposes to know
> the wire protocol used for remote operations. This may differ from the
> version set in local configuration due to differences in version and/or
> configuration between the server and the client. Therefore, log the
> negotiated wire protocol version via trace2, for both clients and
> servers.
>
> Signed-off-by: Josh Steadmon <steadmon@google.com>
> ---

I know Taylor asked you to change it to a string from in int upthread in
<YQmxSxTswHE/gTet@nand.local>, but I really don't see the point. But am
willing to be convinced otherwise.

It seems to me that both of these codepaths will never usefully use this
new "UNKNOWN_VERSION" string you added, i.e.:

>  connect.c                             |  3 +++
>  protocol.c                            |  3 +++
>  t/t5705-session-id-in-capabilities.sh | 12 ++++++++++++
>  3 files changed, 18 insertions(+)
>
> diff --git a/connect.c b/connect.c
> index 70b13389ba..5f0e113625 100644
> --- a/connect.c
> +++ b/connect.c
> @@ -150,6 +150,9 @@ enum protocol_version discover_version(struct packet_reader *reader)
>  		break;
>  	}
>  
> +	trace2_data_string("transfer", NULL, "negotiated-version",
> +			   format_protocol_version(version));

Right after this.

>  	switch (version) {
>  	case protocol_v2:
>  		process_capabilities_v2(reader);

We'll die here with BUG("unknown protocol version") if it's unknown..

> diff --git a/protocol.c b/protocol.c
> index 7ec7ce896e..f52dc2d7a2 100644
> --- a/protocol.c
> +++ b/protocol.c
> @@ -87,6 +87,9 @@ enum protocol_version determine_protocol_version_server(void)
>  		string_list_clear(&list, 0);
>  	}
>  
> +	trace2_data_string("transfer", NULL, "negotiated-version",
> +			   format_protocol_version(version));
> +

And this code is simply unreachable as far as logging this
"UNKNOWN_VERSION" string goes. If we did have an unknown version we'd
die right above this with:

    die("server is speaking an unknown protocol")

And if we did not have a "version " at all we'd default to protocol_v0
here, i.e. we either die already on an unknown version, or we don't log
"UNKNOWN_VERSION" at all.

>  	return version;
>  }
>  
> diff --git a/t/t5705-session-id-in-capabilities.sh b/t/t5705-session-id-in-capabilities.sh
> index f1d189d5bc..88871c59b5 100755
> --- a/t/t5705-session-id-in-capabilities.sh
> +++ b/t/t5705-session-id-in-capabilities.sh
> @@ -40,6 +40,7 @@ do
>  		test -z "$(grep \"key\":\"server-sid\" tr2-client-events)" &&
>  		test -z "$(grep \"key\":\"client-sid\" tr2-server-events)"
>  	'
> +
>  done
>  
>  test_expect_success 'enable SID advertisement' '
> @@ -73,6 +74,17 @@ do
>  		grep \"key\":\"server-sid\" tr2-client-events &&
>  		grep \"key\":\"client-sid\" tr2-server-events
>  	'
> +
> +	test_expect_success "client & server log negotiated version (v${PROTO})" '
> +		test_when_finished "rm -rf local tr2-client-events tr2-server-events" &&
> +		cp -r "$LOCAL_PRISTINE" local &&
> +		GIT_TRACE2_EVENT="$(pwd)/tr2-client-events" \
> +		git -c protocol.version=$PROTO -C local fetch \
> +			--upload-pack "GIT_TRACE2_EVENT=\"$(pwd)/tr2-server-events\" git-upload-pack" \
> +			origin &&
> +		test "$(grep \"key\":\"negotiated-version\",\"value\":\"$PROTO\" tr2-client-events)" &&
> +		test "$(grep \"key\":\"negotiated-version\",\"value\":\"$PROTO\" tr2-server-events)"
> +	'
>  done
>  
>  test_done

So given the above I think you can come up with trace2 output where we
log "UNKNOWN_VERSION", it just seems rather useless. We'll hit a BUG()
anyway, which we also trace2 log. In terms of anyone who collect logs
surely they'll first care about logged BUG(), and second about any
version aggregation involved in such a BUG(), and it's not a big deal if
the report of versions doesn't include the "UNKNOWN VERSION" to go with
such a one-off bug.

But perhaps you and Taylor really do have a use-case for this, hence the
"willing to be convinced otherwise". I suspect the desire to log
"<unknown>" came from an assumption that we did so in any recoverable
non-BUG() case, which we won't do.