From 7220c2c2143f13081bf4ae4fd21b29c25c67540b Mon Sep 17 00:00:00 2001
From: Nuno Diegues <nuno@cloudflare.com>
Date: Fri, 4 Mar 2022 09:31:40 +0000
Subject: [PATCH] TUN-5837: Log panic recovery in http2 logic with debug level
 log

---
 connection/http2.go                | 13 ++++++++-----
 orchestration/orchestrator_test.go |  9 ++++++---
 websocket/websocket.go             |  3 ++-
 3 files changed, 16 insertions(+), 9 deletions(-)

diff --git a/connection/http2.go b/connection/http2.go
index d1e78c1f..b015117c 100644
--- a/connection/http2.go
+++ b/connection/http2.go
@@ -100,7 +100,7 @@ func (c *HTTP2Connection) ServeHTTP(w http.ResponseWriter, r *http.Request) {
 	connType := determineHTTP2Type(r)
 	handleMissingRequestParts(connType, r)
 
-	respWriter, err := NewHTTP2RespWriter(r, w, connType)
+	respWriter, err := NewHTTP2RespWriter(r, w, connType, c.log)
 	if err != nil {
 		c.observer.log.Error().Msg(err.Error())
 		return
@@ -163,14 +163,16 @@ type http2RespWriter struct {
 	w           http.ResponseWriter
 	flusher     http.Flusher
 	shouldFlush bool
+	log         *zerolog.Logger
 }
 
-func NewHTTP2RespWriter(r *http.Request, w http.ResponseWriter, connType Type) (*http2RespWriter, error) {
+func NewHTTP2RespWriter(r *http.Request, w http.ResponseWriter, connType Type, log *zerolog.Logger) (*http2RespWriter, error) {
 	flusher, isFlusher := w.(http.Flusher)
 	if !isFlusher {
 		respWriter := &http2RespWriter{
-			r: r.Body,
-			w: w,
+			r:   r.Body,
+			w:   w,
+			log: log,
 		}
 		respWriter.WriteErrorResponse()
 		return nil, fmt.Errorf("%T doesn't implement http.Flusher", w)
@@ -181,6 +183,7 @@ func NewHTTP2RespWriter(r *http.Request, w http.ResponseWriter, connType Type) (
 		w:           w,
 		flusher:     flusher,
 		shouldFlush: connType.shouldFlush(),
+		log:         log,
 	}, nil
 }
 
@@ -239,7 +242,7 @@ func (rp *http2RespWriter) Write(p []byte) (n int, err error) {
 		// Implementer of OriginClient should make sure it doesn't write to the connection after Proxy returns
 		// Register a recover routine just in case.
 		if r := recover(); r != nil {
-			println(fmt.Sprintf("Recover from http2 response writer panic, error %s", debug.Stack()))
+			rp.log.Debug().Msgf("Recover from http2 response writer panic, error %s", debug.Stack())
 		}
 	}()
 	n, err = rp.w.Write(p)
diff --git a/orchestration/orchestrator_test.go b/orchestration/orchestrator_test.go
index b4b19224..4fe6c7b1 100644
--- a/orchestration/orchestrator_test.go
+++ b/orchestration/orchestrator_test.go
@@ -332,7 +332,8 @@ func proxyHTTP(t *testing.T, originProxy connection.OriginProxy, hostname string
 	require.NoError(t, err)
 
 	w := httptest.NewRecorder()
-	respWriter, err := connection.NewHTTP2RespWriter(req, w, connection.TypeHTTP)
+	log := zerolog.Nop()
+	respWriter, err := connection.NewHTTP2RespWriter(req, w, connection.TypeHTTP, &log)
 	require.NoError(t, err)
 
 	err = originProxy.ProxyHTTP(respWriter, req, false)
@@ -358,7 +359,8 @@ func proxyTCP(t *testing.T, originProxy connection.OriginProxy, originAddr strin
 	req, err := http.NewRequest(http.MethodGet, fmt.Sprintf("http://%s", originAddr), reqBody)
 	require.NoError(t, err)
 
-	respWriter, err := connection.NewHTTP2RespWriter(req, w, connection.TypeTCP)
+	log := zerolog.Nop()
+	respWriter, err := connection.NewHTTP2RespWriter(req, w, connection.TypeTCP, &log)
 	require.NoError(t, err)
 
 	tcpReq := &connection.TCPRequest{
@@ -578,7 +580,8 @@ func TestPersistentConnection(t *testing.T) {
 		// ProxyHTTP will add Connection, Upgrade and Sec-Websocket-Version headers
 		req.Header.Add("Sec-WebSocket-Key", "dGhlIHNhbXBsZSBub25jZQ==")
 
-		respWriter, err := connection.NewHTTP2RespWriter(req, wsRespReadWriter, connection.TypeWebsocket)
+		log := zerolog.Nop()
+		respWriter, err := connection.NewHTTP2RespWriter(req, wsRespReadWriter, connection.TypeWebsocket, &log)
 		require.NoError(t, err)
 
 		err = originProxy.ProxyHTTP(respWriter, req, true)
diff --git a/websocket/websocket.go b/websocket/websocket.go
index 67c8916b..7240e368 100644
--- a/websocket/websocket.go
+++ b/websocket/websocket.go
@@ -8,6 +8,7 @@ import (
 	"fmt"
 	"io"
 	"net/http"
+	"runtime/debug"
 	"sync/atomic"
 	"time"
 
@@ -77,7 +78,7 @@ func unidirectionalStream(dst io.Writer, src io.Reader, dir string, status *bidi
 			// exited. In such case, we stop a possible panic from propagating upstream.
 			if r := recover(); r != nil {
 				// We handle such unexpected errors only when we detect that one side of the streaming is done.
-				log.Debug().Msgf("Handled gracefully error %v in Streaming for %s", r, dir)
+				log.Debug().Msgf("Gracefully handled error %v in Streaming for %s, error %s", r, dir, debug.Stack())
 			}
 		}
 	}()