Use %v instead of %s in relay logs (#224)

drigz · web-flow · commit 4d52ba085525 · 2023-09-15T08:49:57.000Z
This doesn't change the formatting but is more consistent with our other
error format strings.

I also fixed the location of a string due to an unclear review comment I
made.
diff --git a/src/go/cmd/http-relay-client/client/client.go b/src/go/cmd/http-relay-client/client/client.go
@@ -396,9 +396,9 @@ func (c *Client) postResponse(remote *http.Client, br *pb.HttpResponse) error {
 		return fmt.Errorf("couldn't read relay server's response body: %v", err)
 	}
 	if resp.StatusCode != http.StatusOK {
-		err := NewRelayServerError(fmt.Sprintf("relay server responded %s or the client cancelled the request: %s", http.StatusText(resp.StatusCode), body))
+		err := NewRelayServerError(fmt.Sprintf("relay server responded %s: %s", http.StatusText(resp.StatusCode), body))
 		if resp.StatusCode == http.StatusBadRequest {
-			// http-relay-server may have restarted during the request.
+			// http-relay-server may have restarted or the client cancelled the request.
 			return backoff.Permanent(err)
 		}
 		return err
@@ -660,7 +660,7 @@ func (c *Client) handleRequest(remote *http.Client, local *http.Client, pbreq *p
 		// A missing chunk will cause clients to receive corrupted data, in most cases it is better
 		// to close the connection to avoid that.
 		if err != nil {
-			log.Printf("[%s] Closing backend connection (%s)", *resp.Id, err)
+			log.Printf("[%s] Closing backend connection: %v", *resp.Id, err)
 			break
 		}
 	}
diff --git a/src/go/cmd/http-relay-client/client/client_test.go b/src/go/cmd/http-relay-client/client/client_test.go
@@ -106,7 +106,7 @@ func TestLocalProxy(t *testing.T) {
 	client := NewClient(config)
 	err := client.localProxy(&http.Client{}, &http.Client{})
 	if err != nil {
-		t.Errorf("Unexpected error: %s", err)
+		t.Errorf("Unexpected error: %v", err)
 	}
 	assertMocksDoneWithin(t, 10*time.Second)
 }
@@ -175,7 +175,7 @@ func TestBackendError(t *testing.T) {
 	// 3. retrieves the response from the backend and sends it to the relay-server
 	err := client.localProxy(&http.Client{}, &http.Client{})
 	if err != nil {
-		t.Errorf("Unexpected error: %s", err)
+		t.Errorf("Unexpected error: %v", err)
 	}
 	assertMocksDoneWithin(t, 10*time.Second)
 }
@@ -206,7 +206,7 @@ func TestServerTimeout(t *testing.T) {
 	client := NewClient(config)
 	err := client.localProxy(&http.Client{}, &http.Client{})
 	if err != ErrTimeout {
-		t.Errorf("Unexpected error: %s", err)
+		t.Errorf("Unexpected error: %v", err)
 	}
 	assertMocksDoneWithin(t, 10*time.Second)
 }
diff --git a/src/go/cmd/http-relay-server/server/broker_test.go b/src/go/cmd/http-relay-server/server/broker_test.go
@@ -54,11 +54,11 @@ func runSender(t *testing.T, b *broker, s string, m string, wg *sync.WaitGroup)
 func runReceiver(t *testing.T, b *broker, s string, wg *sync.WaitGroup) {
 	req, err := b.GetRequest(context.Background(), s, "/")
 	if err != nil {
-		t.Errorf("Error when getting request: %s", err)
+		t.Errorf("Error when getting request: %v", err)
 	}
 	err = b.SendResponse(&pb.HttpResponse{Id: req.Id, Body: []byte(*req.Id), Eof: proto.Bool(true)})
 	if err != nil {
-		t.Errorf("Error when sending response: %s", err)
+		t.Errorf("Error when sending response: %v", err)
 	}
 	wg.Done()
 }
@@ -89,17 +89,17 @@ func runSenderStream(t *testing.T, b *broker, s string, m string, wg *sync.WaitG
 func runReceiverStream(t *testing.T, b *broker, s string, wg *sync.WaitGroup, done <-chan bool) {
 	req, err := b.GetRequest(context.Background(), s, "/")
 	if err != nil {
-		t.Errorf("Error when getting request: %s", err)
+		t.Errorf("Error when getting request: %v", err)
 	}
 	err = b.SendResponse(&pb.HttpResponse{Id: req.Id, Body: []byte(*req.Id), Eof: proto.Bool(false)})
 	if err != nil {
-		t.Errorf("Error when sending response: %s", err)
+		t.Errorf("Error when sending response: %v", err)
 	}
 	go func() {
 		<-done
 		err = b.SendResponse(&pb.HttpResponse{Id: req.Id, Body: []byte(*req.Id), Eof: proto.Bool(true)})
 		if err != nil {
-			t.Errorf("Error when sending response: %s", err)
+			t.Errorf("Error when sending response: %v", err)
 		}
 		wg.Done()
 	}()
diff --git a/src/go/cmd/http-relay-server/server/server.go b/src/go/cmd/http-relay-server/server/server.go
@@ -258,7 +258,7 @@ func (s *Server) bidirectionalStream(backendCtx backendContext, w http.ResponseW
 	numBytes := 0
 	for responseChunk := range responseChunks {
 		if _, err = w.Write(responseChunk.Body); err != nil {
-			log.Printf("[%s] %s", backendCtx.Id, err)
+			log.Printf("[%s] Error writing response to bidi-stream: %v", backendCtx.Id, err)
 			return
 		}
 		bufrw.Flush()
@@ -396,7 +396,7 @@ func (s *Server) userClientRequest(w http.ResponseWriter, r *http.Request) {
 	numBytes := 0
 	for responseChunk := range responseChunksChan {
 		if _, err = w.Write(responseChunk.Body); err != nil {
-			log.Printf("[%s] %s", backendCtx.Id, err)
+			log.Printf("[%s] Error writing response to user-client: %v", backendCtx.Id, err)
 			return
 		}
 		if flush, ok := w.(http.Flusher); ok {
@@ -558,6 +558,6 @@ func (s *Server) Start(port int, blockSize int) {
 		// update) or a failed liveness check (eg broker deadlock), we can't
 		// easily tell. We panic to help debugging: if the environment sets
 		// GOTRACEBACK=all they will see stacktraces after the panic.
-		log.Panicf("Server terminated abnormally: %s", err)
+		log.Panicf("Server terminated abnormally: %v", err)
 	}
 }
diff --git a/src/go/cmd/http-relay-server/server/server_test.go b/src/go/cmd/http-relay-server/server/server_test.go
@@ -223,7 +223,7 @@ func TestClientBadRequest(t *testing.T) {
 			if tc.wantMsg != "" {
 				body, err := ioutil.ReadAll(resp.Body)
 				if err != nil {
-					t.Errorf("Failed to read body stream: %s", err)
+					t.Errorf("Failed to read body stream: %v", err)
 				}
 				if !strings.Contains(string(body), tc.wantMsg) {
 					t.Errorf("Wrong response body; want %q; got %q", tc.wantMsg, body)
@@ -326,7 +326,7 @@ func TestServerRequestResponseHandler(t *testing.T) {
 	}
 	backendRespBody, err := proto.Marshal(backendResp)
 	if err != nil {
-		t.Errorf("Failed to marshal test response: %s", err)
+		t.Errorf("Failed to marshal test response: %v", err)
 	}
 
 	req := httptest.NewRequest("GET", "/server/request?server=b", strings.NewReader(""))
@@ -354,7 +354,7 @@ func TestServerRequestResponseHandler(t *testing.T) {
 	}
 	body, err := ioutil.ReadAll(reqRecorder.Result().Body)
 	if err != nil {
-		t.Errorf("Failed to read body stream: %s", err)
+		t.Errorf("Failed to read body stream: %v", err)
 	}
 	if !strings.Contains(string(body), "/my/url") {
 		t.Errorf("Serialize request didn't contain URL: %s", string(body))
@@ -385,7 +385,7 @@ func TestServerResponseHandlerWithInvalidRequestID(t *testing.T) {
 	}
 	backendRespBody, err := proto.Marshal(backendResp)
 	if err != nil {
-		t.Errorf("Failed to marshal test response: %s", err)
+		t.Errorf("Failed to marshal test response: %v", err)
 	}
 
 	resp := httptest.NewRequest("POST", "/server/response", bytes.NewReader(backendRespBody))

Original file line number	Diff line number	Diff line change
`@@ -396,9 +396,9 @@ func (c Client) postResponse(remote http.Client, br *pb.HttpResponse) error {`
`396`	`396`	`return fmt.Errorf("couldn't read relay server's response body: %v", err)`
`397`	`397`	`}`
`398`	`398`	`if resp.StatusCode != http.StatusOK {`
`399`		`- err := NewRelayServerError(fmt.Sprintf("relay server responded %s or the client cancelled the request: %s", http.StatusText(resp.StatusCode), body))`
	`399`	`+ err := NewRelayServerError(fmt.Sprintf("relay server responded %s: %s", http.StatusText(resp.StatusCode), body))`
`400`	`400`	`if resp.StatusCode == http.StatusBadRequest {`
`401`		`- // http-relay-server may have restarted during the request.`
	`401`	`+ // http-relay-server may have restarted or the client cancelled the request.`
`402`	`402`	`return backoff.Permanent(err)`
`403`	`403`	`}`
`404`	`404`	`return err`
`@@ -660,7 +660,7 @@ func (c Client) handleRequest(remote http.Client, local http.Client, pbreq p`
`660`	`660`	`// A missing chunk will cause clients to receive corrupted data, in most cases it is better`
`661`	`661`	`// to close the connection to avoid that.`
`662`	`662`	`if err != nil {`
`663`		`- log.Printf("[%s] Closing backend connection (%s)", *resp.Id, err)`
	`663`	`+ log.Printf("[%s] Closing backend connection: %v", *resp.Id, err)`
`664`	`664`	`break`
`665`	`665`	`}`
`666`	`666`	`}`
Original file line number	Diff line number	Diff line change
`@@ -106,7 +106,7 @@ func TestLocalProxy(t *testing.T) {`
`106`	`106`	`client := NewClient(config)`
`107`	`107`	`err := client.localProxy(&http.Client{}, &http.Client{})`
`108`	`108`	`if err != nil {`
`109`		`- t.Errorf("Unexpected error: %s", err)`
	`109`	`+ t.Errorf("Unexpected error: %v", err)`
`110`	`110`	`}`
`111`	`111`	`assertMocksDoneWithin(t, 10*time.Second)`
`112`	`112`	`}`
`@@ -175,7 +175,7 @@ func TestBackendError(t *testing.T) {`
`175`	`175`	`// 3. retrieves the response from the backend and sends it to the relay-server`
`176`	`176`	`err := client.localProxy(&http.Client{}, &http.Client{})`
`177`	`177`	`if err != nil {`
`178`		`- t.Errorf("Unexpected error: %s", err)`
	`178`	`+ t.Errorf("Unexpected error: %v", err)`
`179`	`179`	`}`
`180`	`180`	`assertMocksDoneWithin(t, 10*time.Second)`
`181`	`181`	`}`
`@@ -206,7 +206,7 @@ func TestServerTimeout(t *testing.T) {`
`206`	`206`	`client := NewClient(config)`
`207`	`207`	`err := client.localProxy(&http.Client{}, &http.Client{})`
`208`	`208`	`if err != ErrTimeout {`
`209`		`- t.Errorf("Unexpected error: %s", err)`
	`209`	`+ t.Errorf("Unexpected error: %v", err)`
`210`	`210`	`}`
`211`	`211`	`assertMocksDoneWithin(t, 10*time.Second)`
`212`	`212`	`}`
Original file line number	Diff line number	Diff line change
`@@ -54,11 +54,11 @@ func runSender(t testing.T, b broker, s string, m string, wg *sync.WaitGroup)`
`54`	`54`	`func runReceiver(t testing.T, b broker, s string, wg *sync.WaitGroup) {`
`55`	`55`	`req, err := b.GetRequest(context.Background(), s, "/")`
`56`	`56`	`if err != nil {`
`57`		`- t.Errorf("Error when getting request: %s", err)`
	`57`	`+ t.Errorf("Error when getting request: %v", err)`
`58`	`58`	`}`
`59`	`59`	`err = b.SendResponse(&pb.HttpResponse{Id: req.Id, Body: []byte(*req.Id), Eof: proto.Bool(true)})`
`60`	`60`	`if err != nil {`
`61`		`- t.Errorf("Error when sending response: %s", err)`
	`61`	`+ t.Errorf("Error when sending response: %v", err)`
`62`	`62`	`}`
`63`	`63`	`wg.Done()`
`64`	`64`	`}`
`@@ -89,17 +89,17 @@ func runSenderStream(t testing.T, b broker, s string, m string, wg *sync.WaitG`
`89`	`89`	`func runReceiverStream(t testing.T, b broker, s string, wg *sync.WaitGroup, done <-chan bool) {`
`90`	`90`	`req, err := b.GetRequest(context.Background(), s, "/")`
`91`	`91`	`if err != nil {`
`92`		`- t.Errorf("Error when getting request: %s", err)`
	`92`	`+ t.Errorf("Error when getting request: %v", err)`
`93`	`93`	`}`
`94`	`94`	`err = b.SendResponse(&pb.HttpResponse{Id: req.Id, Body: []byte(*req.Id), Eof: proto.Bool(false)})`
`95`	`95`	`if err != nil {`
`96`		`- t.Errorf("Error when sending response: %s", err)`
	`96`	`+ t.Errorf("Error when sending response: %v", err)`
`97`	`97`	`}`
`98`	`98`	`go func() {`
`99`	`99`	`<-done`
`100`	`100`	`err = b.SendResponse(&pb.HttpResponse{Id: req.Id, Body: []byte(*req.Id), Eof: proto.Bool(true)})`
`101`	`101`	`if err != nil {`
`102`		`- t.Errorf("Error when sending response: %s", err)`
	`102`	`+ t.Errorf("Error when sending response: %v", err)`
`103`	`103`	`}`
`104`	`104`	`wg.Done()`
`105`	`105`	`}()`
Original file line number	Diff line number	Diff line change
`@@ -258,7 +258,7 @@ func (s *Server) bidirectionalStream(backendCtx backendContext, w http.ResponseW`
`258`	`258`	`numBytes := 0`
`259`	`259`	`for responseChunk := range responseChunks {`
`260`	`260`	`if _, err = w.Write(responseChunk.Body); err != nil {`
`261`		`- log.Printf("[%s] %s", backendCtx.Id, err)`
	`261`	`+ log.Printf("[%s] Error writing response to bidi-stream: %v", backendCtx.Id, err)`
`262`	`262`	`return`
`263`	`263`	`}`
`264`	`264`	`bufrw.Flush()`
`@@ -396,7 +396,7 @@ func (s Server) userClientRequest(w http.ResponseWriter, r http.Request) {`
`396`	`396`	`numBytes := 0`
`397`	`397`	`for responseChunk := range responseChunksChan {`
`398`	`398`	`if _, err = w.Write(responseChunk.Body); err != nil {`
`399`		`- log.Printf("[%s] %s", backendCtx.Id, err)`
	`399`	`+ log.Printf("[%s] Error writing response to user-client: %v", backendCtx.Id, err)`
`400`	`400`	`return`
`401`	`401`	`}`
`402`	`402`	`if flush, ok := w.(http.Flusher); ok {`
`@@ -558,6 +558,6 @@ func (s *Server) Start(port int, blockSize int) {`
`558`	`558`	`// update) or a failed liveness check (eg broker deadlock), we can't`
`559`	`559`	`// easily tell. We panic to help debugging: if the environment sets`
`560`	`560`	`// GOTRACEBACK=all they will see stacktraces after the panic.`
`561`		`- log.Panicf("Server terminated abnormally: %s", err)`
	`561`	`+ log.Panicf("Server terminated abnormally: %v", err)`
`562`	`562`	`}`
`563`	`563`	`}`
Original file line number	Diff line number	Diff line change
`@@ -223,7 +223,7 @@ func TestClientBadRequest(t *testing.T) {`
`223`	`223`	`if tc.wantMsg != "" {`
`224`	`224`	`body, err := ioutil.ReadAll(resp.Body)`
`225`	`225`	`if err != nil {`
`226`		`- t.Errorf("Failed to read body stream: %s", err)`
	`226`	`+ t.Errorf("Failed to read body stream: %v", err)`
`227`	`227`	`}`
`228`	`228`	`if !strings.Contains(string(body), tc.wantMsg) {`
`229`	`229`	`t.Errorf("Wrong response body; want %q; got %q", tc.wantMsg, body)`
`@@ -326,7 +326,7 @@ func TestServerRequestResponseHandler(t *testing.T) {`
`326`	`326`	`}`
`327`	`327`	`backendRespBody, err := proto.Marshal(backendResp)`
`328`	`328`	`if err != nil {`
`329`		`- t.Errorf("Failed to marshal test response: %s", err)`
	`329`	`+ t.Errorf("Failed to marshal test response: %v", err)`
`330`	`330`	`}`
`331`	`331`
`332`	`332`	`req := httptest.NewRequest("GET", "/server/request?server=b", strings.NewReader(""))`
`@@ -354,7 +354,7 @@ func TestServerRequestResponseHandler(t *testing.T) {`
`354`	`354`	`}`
`355`	`355`	`body, err := ioutil.ReadAll(reqRecorder.Result().Body)`
`356`	`356`	`if err != nil {`
`357`		`- t.Errorf("Failed to read body stream: %s", err)`
	`357`	`+ t.Errorf("Failed to read body stream: %v", err)`
`358`	`358`	`}`
`359`	`359`	`if !strings.Contains(string(body), "/my/url") {`
`360`	`360`	`t.Errorf("Serialize request didn't contain URL: %s", string(body))`
`@@ -385,7 +385,7 @@ func TestServerResponseHandlerWithInvalidRequestID(t *testing.T) {`
`385`	`385`	`}`
`386`	`386`	`backendRespBody, err := proto.Marshal(backendResp)`
`387`	`387`	`if err != nil {`
`388`		`- t.Errorf("Failed to marshal test response: %s", err)`
	`388`	`+ t.Errorf("Failed to marshal test response: %v", err)`
`389`	`389`	`}`
`390`	`390`
`391`	`391`	`resp := httptest.NewRequest("POST", "/server/response", bytes.NewReader(backendRespBody))`