From 8ad04f7dbbd8defb5277d5cfc8f6990b2a5f7240 Mon Sep 17 00:00:00 2001
From: Malte Poll <1780588+malt3@users.noreply.github.com>
Date: Fri, 3 Mar 2023 09:38:57 +0100
Subject: [PATCH] cli: log grpc connection state for init call (#1324)

This is a measure to detect cases where an aTLS handshake is performed but the long running call is interrupted, leading to a retry of the init call.
Whenever the grpc connection state reaches ready, we know that the aTLS handshake has succeeded:

> READY: The channel has successfully established a connection all the way through TLS handshake (or equivalent) and protocol-level (HTTP/2, etc) handshaking, and all subsequent attempt to communicate have succeeded (or are pending without any known failure).
---
 cli/internal/cmd/init.go | 27 +++++++++++++++++++++++++++
 1 file changed, 27 insertions(+)

diff --git a/cli/internal/cmd/init.go b/cli/internal/cmd/init.go
index 53f40001c..3c5a085bf 100644
--- a/cli/internal/cmd/init.go
+++ b/cli/internal/cmd/init.go
@@ -15,6 +15,7 @@ import (
 	"net"
 	"os"
 	"strconv"
+	"sync"
 	"text/tabwriter"
 	"time"
 
@@ -40,6 +41,7 @@ import (
 	"github.com/spf13/afero"
 	"github.com/spf13/cobra"
 	"google.golang.org/grpc"
+	"google.golang.org/grpc/connectivity"
 	"k8s.io/apimachinery/pkg/runtime"
 	"k8s.io/client-go/tools/clientcmd"
 	clientcmdapi "k8s.io/client-go/tools/clientcmd/api"
@@ -232,6 +234,15 @@ func (d *initDoer) Do(ctx context.Context) error {
 		return fmt.Errorf("dialing init server: %w", err)
 	}
 	defer conn.Close()
+
+	var wg sync.WaitGroup
+	defer wg.Wait()
+
+	grpcStateLogCtx, grpcStateLogCancel := context.WithCancel(ctx)
+	defer grpcStateLogCancel()
+	wg.Add(1)
+	d.logGRPCStateChanges(grpcStateLogCtx, &wg, conn)
+
 	protoClient := initproto.NewAPIClient(conn)
 	d.log.Debugf("Created protoClient")
 	resp, err := protoClient.Init(ctx, d.req)
@@ -242,6 +253,22 @@ func (d *initDoer) Do(ctx context.Context) error {
 	return nil
 }
 
+func (d *initDoer) logGRPCStateChanges(ctx context.Context, wg *sync.WaitGroup, conn *grpc.ClientConn) {
+	go func() {
+		defer wg.Done()
+		state := conn.GetState()
+		d.log.Debugf("Connection state started as %s", state)
+		for ; state != connectivity.Ready && conn.WaitForStateChange(ctx, state); state = conn.GetState() {
+			d.log.Debugf("Connection state changed to %s", state)
+		}
+		if state == connectivity.Ready {
+			d.log.Debugf("Connection ready")
+		} else {
+			d.log.Debugf("Connection state ended with %s", state)
+		}
+	}()
+}
+
 func (i *initCmd) writeOutput(
 	idFile clusterid.File, resp *initproto.InitResponse, mergeConfig bool, wr io.Writer, fileHandler file.Handler,
 ) error {