From ad57fea4c59e1e9d60b26c6a9d7fc48b0bb79a64 Mon Sep 17 00:00:00 2001
From: Jordan Liggitt <liggitt@google.com>
Date: Wed, 19 Aug 2020 09:40:09 -0400
Subject: [PATCH] etcdserver: Avoid panics logging slow v2 requests in
 integration tests

---
 etcdserver/apply_v2.go  |  7 ++++++-
 etcdserver/util.go      | 18 ++++++++++++++++++
 etcdserver/util_test.go | 20 ++++++++++++++++++++
 3 files changed, 44 insertions(+), 1 deletion(-)

diff --git a/etcdserver/apply_v2.go b/etcdserver/apply_v2.go
index ad88f4657e8..48bfc6685b9 100644
--- a/etcdserver/apply_v2.go
+++ b/etcdserver/apply_v2.go
@@ -16,6 +16,7 @@ package etcdserver
 
 import (
 	"encoding/json"
+	"fmt"
 	"path"
 	"time"
 
@@ -109,7 +110,11 @@ func (a *applierV2store) Sync(r *RequestV2) Response {
 // applyV2Request interprets r as a call to v2store.X
 // and returns a Response interpreted from v2store.Event
 func (s *EtcdServer) applyV2Request(r *RequestV2) Response {
-	defer warnOfExpensiveRequest(s.getLogger(), time.Now(), r, nil, nil)
+	stringer := panicAlternativeStringer{
+		stringer:    r,
+		alternative: func() string { return fmt.Sprintf("id:%d,method:%s,path:%s", r.ID, r.Method, r.Path) },
+	}
+	defer warnOfExpensiveRequest(s.getLogger(), time.Now(), stringer, nil, nil)
 
 	switch r.Method {
 	case "POST":
diff --git a/etcdserver/util.go b/etcdserver/util.go
index 6dfa5fd4516..91b3f72c97f 100644
--- a/etcdserver/util.go
+++ b/etcdserver/util.go
@@ -171,3 +171,21 @@ func warnOfExpensiveGenericRequest(lg *zap.Logger, now time.Time, reqStringer fm
 func isNil(msg proto.Message) bool {
 	return msg == nil || reflect.ValueOf(msg).IsNil()
 }
+
+// panicAlternativeStringer wraps a fmt.Stringer, and if calling String() panics, calls the alternative instead.
+// This is needed to ensure logging slow v2 requests does not panic, which occurs when running integration tests
+// with the embedded server with github.com/golang/protobuf v1.4.0+. See https://github.com/etcd-io/etcd/issues/12197.
+type panicAlternativeStringer struct {
+	stringer    fmt.Stringer
+	alternative func() string
+}
+
+func (n panicAlternativeStringer) String() (s string) {
+	defer func() {
+		if err := recover(); err != nil {
+			s = n.alternative()
+		}
+	}()
+	s = n.stringer.String()
+	return s
+}
diff --git a/etcdserver/util_test.go b/etcdserver/util_test.go
index 3c4ee7ee94d..8a5c54d7289 100644
--- a/etcdserver/util_test.go
+++ b/etcdserver/util_test.go
@@ -90,3 +90,23 @@ func (s *nopTransporterWithActiveTime) Stop()                               {}
 func (s *nopTransporterWithActiveTime) Pause()                              {}
 func (s *nopTransporterWithActiveTime) Resume()                             {}
 func (s *nopTransporterWithActiveTime) reset(am map[types.ID]time.Time)     { s.activeMap = am }
+
+func TestPanicAlternativeStringer(t *testing.T) {
+	p := panicAlternativeStringer{alternative: func() string { return "alternative" }}
+
+	p.stringer = testStringerFunc(func() string { panic("here") })
+	if s := p.String(); s != "alternative" {
+		t.Fatalf("expected 'alternative', got %q", s)
+	}
+
+	p.stringer = testStringerFunc(func() string { return "test" })
+	if s := p.String(); s != "test" {
+		t.Fatalf("expected 'test', got %q", s)
+	}
+}
+
+type testStringerFunc func() string
+
+func (s testStringerFunc) String() string {
+	return s()
+}