From 3ead27a3a2ddf853ad5ab5ee1e6046a399dea98d Mon Sep 17 00:00:00 2001
From: Sean Sullivan <seans@google.com>
Date: Tue, 11 Feb 2025 20:20:23 +0000
Subject: [PATCH] Update websocket logging levels for better debuggability

Kubernetes-commit: d3feb5080c18fa73aa87c81a78d5cac82c6ed06d
---
 tools/remotecommand/websocket.go | 17 +++++++++--------
 1 file changed, 9 insertions(+), 8 deletions(-)

diff --git a/tools/remotecommand/websocket.go b/tools/remotecommand/websocket.go
index 1dc679cb..7e7703ca 100644
--- a/tools/remotecommand/websocket.go
+++ b/tools/remotecommand/websocket.go
@@ -248,6 +248,7 @@ func (c *wsStreamCreator) readDemuxLoop(bufferSize int, period time.Duration, de
 	// Initialize and start the ping/pong heartbeat.
 	h := newHeartbeat(c.conn, period, deadline)
 	// Set initial timeout for websocket connection reading.
+	klog.V(5).Infof("Websocket initial read deadline: %s", deadline)
 	if err := c.conn.SetReadDeadline(time.Now().Add(deadline)); err != nil {
 		klog.Errorf("Websocket initial setting read deadline failed %v", err)
 		return
@@ -354,8 +355,8 @@ func (s *stream) Read(p []byte) (n int, err error) {
 
 // Write writes directly to the underlying WebSocket connection.
 func (s *stream) Write(p []byte) (n int, err error) {
-	klog.V(4).Infof("Write() on stream %d", s.id)
-	defer klog.V(4).Infof("Write() done on stream %d", s.id)
+	klog.V(8).Infof("Write() on stream %d", s.id)
+	defer klog.V(8).Infof("Write() done on stream %d", s.id)
 	s.connWriteLock.Lock()
 	defer s.connWriteLock.Unlock()
 	if s.conn == nil {
@@ -363,7 +364,7 @@ func (s *stream) Write(p []byte) (n int, err error) {
 	}
 	err = s.conn.SetWriteDeadline(time.Now().Add(writeDeadline))
 	if err != nil {
-		klog.V(7).Infof("Websocket setting write deadline failed %v", err)
+		klog.V(4).Infof("Websocket setting write deadline failed %v", err)
 		return 0, err
 	}
 	// Message writer buffers the message data, so we don't need to do that ourselves.
@@ -392,8 +393,8 @@ func (s *stream) Write(p []byte) (n int, err error) {
 
 // Close half-closes the stream, indicating this side is finished with the stream.
 func (s *stream) Close() error {
-	klog.V(4).Infof("Close() on stream %d", s.id)
-	defer klog.V(4).Infof("Close() done on stream %d", s.id)
+	klog.V(6).Infof("Close() on stream %d", s.id)
+	defer klog.V(6).Infof("Close() done on stream %d", s.id)
 	s.connWriteLock.Lock()
 	defer s.connWriteLock.Unlock()
 	if s.conn == nil {
@@ -452,7 +453,7 @@ func newHeartbeat(conn *gwebsocket.Conn, period time.Duration, deadline time.Dur
 	// be empty.
 	h.conn.SetPongHandler(func(msg string) error {
 		// Push the read deadline into the future.
-		klog.V(8).Infof("Pong message received (%s)--resetting read deadline", msg)
+		klog.V(6).Infof("Pong message received (%s)--resetting read deadline", msg)
 		err := h.conn.SetReadDeadline(time.Now().Add(deadline))
 		if err != nil {
 			klog.Errorf("Websocket setting read deadline failed %v", err)
@@ -487,14 +488,14 @@ func (h *heartbeat) start() {
 	for {
 		select {
 		case <-h.closer:
-			klog.V(8).Infof("closed channel--returning")
+			klog.V(5).Infof("closed channel--returning")
 			return
 		case <-t.C:
 			// "WriteControl" does not need to be protected by a mutex. According to
 			// gorilla/websockets library docs: "The Close and WriteControl methods can
 			// be called concurrently with all other methods."
 			if err := h.conn.WriteControl(gwebsocket.PingMessage, h.message, time.Now().Add(pingReadDeadline)); err == nil {
-				klog.V(8).Infof("Websocket Ping succeeeded")
+				klog.V(6).Infof("Websocket Ping succeeeded")
 			} else {
 				klog.Errorf("Websocket Ping failed: %v", err)
 				if errors.Is(err, gwebsocket.ErrCloseSent) {