Update HTTP and gRPC log middleware/interceptor

debug/debug.go

@@ -22,9 +22,6 @@ type Muxer interface {
 var (
 	// debugLogs is true if debug logs should be enabled.
 	debugLogs bool
-
-	// pprofEnabled is true if pprof handlers are enabled.
-	pprofEnabled bool
 )
 
 // MountDebugLogEnabler mounts an endpoint under "/debug" and returns a HTTP
@@ -54,9 +51,9 @@ func MountDebugLogEnabler(mux Muxer, opts ...DebugLogEnablerOption) {
 			debugLogs = false
 		}
 		if debugLogs {
-			w.Write([]byte(fmt.Sprintf(`{"%s":"%s"}`, o.query, o.onval)))
+			w.Write([]byte(fmt.Sprintf(`{"%s":"%s"}`, o.query, o.onval))) // nolint: errcheck
 		} else {
-			w.Write([]byte(fmt.Sprintf(`{"%s":"%s"}`, o.query, o.offval)))
+			w.Write([]byte(fmt.Sprintf(`{"%s":"%s"}`, o.query, o.offval))) // nolint: errcheck
 		}
 	}))
 }

debug/debug_test.go

@@ -85,7 +85,7 @@ func TestMountPprofHandlers(t *testing.T) {
 			return
 		}
 		w.WriteHeader(http.StatusOK)
-		w.Write([]byte("OK"))
+		w.Write([]byte("OK")) // nolint: errcheck
 	})
 	mux.Handle("/", handler)
 	ts := httptest.NewServer(mux)
@@ -159,7 +159,7 @@ func TestDebugPayloads(t *testing.T) {
 	for _, c := range cases {
 		t.Run(c.name, func(t *testing.T) {
 			buf.Reset()
-			svc.HTTPFunc = func(ctx context.Context, f *testsvc.Fields) (*testsvc.Fields, error) {
+			svc.HTTPFunc = func(_ context.Context, f *testsvc.Fields) (*testsvc.Fields, error) {
 				if c.expectedErr != "" {
 					return nil, errors.New(c.expectedErr)
 				}
@@ -209,6 +209,6 @@ func makeRequest(t *testing.T, url string) (int, string) {
 	}
 	defer res.Body.Close()
 	buf := new(bytes.Buffer)
-	buf.ReadFrom(res.Body)
+	buf.ReadFrom(res.Body) // nolint: errcheck
 	return res.StatusCode, buf.String()
 }

debug/goa_test.go

@@ -12,13 +12,13 @@ import (
 func TestAdapt(t *testing.T) {
 	mux := goahttp.NewMuxer()
 	adapted := Adapt(mux)
-	adapted.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {
+	adapted.HandleFunc("/", func(w http.ResponseWriter, _ *http.Request) {
 		w.WriteHeader(http.StatusOK)
-		w.Write([]byte("OK"))
+		w.Write([]byte("OK")) // nolint: errcheck
 	})
-	adapted.Handle("/foo", http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+	adapted.Handle("/foo", http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) {
 		w.WriteHeader(http.StatusOK)
-		w.Write([]byte("FOO"))
+		w.Write([]byte("FOO")) // nolint: errcheck
 	}))
 	req := &http.Request{Method: "GET", URL: &url.URL{Path: "/"}}
 	w := httptest.NewRecorder()

debug/grpc.go

@@ -15,7 +15,7 @@ func UnaryServerInterceptor() grpc.UnaryServerInterceptor {
 	return func(
 		ctx context.Context,
 		req interface{},
-		info *grpc.UnaryServerInfo,
+		_ *grpc.UnaryServerInfo,
 		handler grpc.UnaryHandler,
 	) (interface{}, error) {
 		if debugLogs {
@@ -35,7 +35,7 @@ func StreamServerInterceptor() grpc.StreamServerInterceptor {
 	return func(
 		srv interface{},
 		stream grpc.ServerStream,
-		info *grpc.StreamServerInfo,
+		_ *grpc.StreamServerInfo,
 		handler grpc.StreamHandler,
 	) error {
 		ctx := stream.Context()

debug/grpc_test.go

@@ -17,7 +17,9 @@ func TestUnaryServerInterceptor(t *testing.T) {
 	var buf bytes.Buffer
 	ctx := log.Context(context.Background(), log.WithOutput(&buf), log.WithFormat(logKeyValsOnly))
 	cli, stop := testsvc.SetupGRPC(t,
-		testsvc.WithServerOptions(grpc.ChainUnaryInterceptor(log.UnaryServerInterceptor(ctx), UnaryServerInterceptor())),
+		testsvc.WithServerOptions(grpc.ChainUnaryInterceptor(
+			log.UnaryServerInterceptor(ctx, log.WithDisableCallLogging()),
+			UnaryServerInterceptor())),
 		testsvc.WithUnaryFunc(logUnaryMethod))
 	defer stop()
 	mux := http.NewServeMux()
@@ -59,7 +61,9 @@ func TestStreamServerInterceptor(t *testing.T) {
 	var buf bytes.Buffer
 	ctx := log.Context(context.Background(), log.WithOutput(&buf), log.WithFormat(logKeyValsOnly))
 	cli, stop := testsvc.SetupGRPC(t,
-		testsvc.WithServerOptions(grpc.ChainStreamInterceptor(log.StreamServerInterceptor(ctx), StreamServerInterceptor())),
+		testsvc.WithServerOptions(grpc.ChainStreamInterceptor(
+			log.StreamServerInterceptor(ctx, log.WithDisableCallLogging()),
+			StreamServerInterceptor())),
 		testsvc.WithStreamFunc(echoMethod))
 	defer stop()
 	steps := []struct {

debug/http_test.go

@@ -11,6 +11,12 @@ import (
 )
 
 func TestHTTP(t *testing.T) {
+	// Create log context
+	var buf bytes.Buffer
+	ctx := log.Context(context.Background(), log.WithOutput(&buf), log.WithFormat(logKeyValsOnly))
+	log.FlushAndDisableBuffering(ctx)
+
+	// Create HTTP handler
 	mux := http.NewServeMux()
 	var handler http.Handler = http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
 		if r.URL.Path != "/" {
@@ -20,17 +26,19 @@ func TestHTTP(t *testing.T) {
 		log.Info(r.Context(), log.KV{K: "test", V: "info"})
 		log.Debug(r.Context(), log.KV{K: "test", V: "debug"})
 		w.WriteHeader(http.StatusOK)
-		w.Write([]byte("OK"))
+		w.Write([]byte("OK")) // nolint: errcheck
 	})
+
+	// Mount debug handler and log middleware
 	MountDebugLogEnabler(mux)
-	var buf bytes.Buffer
-	ctx := log.Context(context.Background(), log.WithOutput(&buf), log.WithFormat(logKeyValsOnly))
-	log.FlushAndDisableBuffering(ctx)
 	handler = HTTP()(handler)
-	handler = log.HTTP(ctx)(handler)
+	handler = log.HTTP(ctx, log.WithDisableRequestLogging())(handler)
+
+	// Start test server
 	mux.Handle("/", handler)
 	ts := httptest.NewServer(mux)
 	defer ts.Close()
+
 	steps := []struct {
 		name         string
 		on           bool

debug/options.go

@@ -27,7 +27,6 @@ type (
 		maxsize int // maximum number of bytes in a single log message or value
 		format  FormatFunc
 		client  bool
-		prefix  string
 	}
 
 	dleOptions struct {
@@ -108,7 +107,7 @@ func WithOffValue(offval string) DebugLogEnablerOption {
 }
 
 // FormatJSON returns a function that formats the given value as JSON.
-func FormatJSON(ctx context.Context, v interface{}) string {
+func FormatJSON(_ context.Context, v interface{}) string {
 	js, err := json.Marshal(v)
 	if err != nil {
 		return fmt.Sprintf("<invalid: %s>", err)

example/weather/services/forecaster/cmd/forecaster/main.go

@@ -12,7 +12,6 @@ import (
 	"syscall"
 	"time"
 
-	grpcmiddleware "github.com/grpc-ecosystem/go-grpc-middleware"
 	"goa.design/clue/debug"
 	"goa.design/clue/health"
 	"goa.design/clue/log"
@@ -45,7 +44,7 @@ func main() {
 		format = log.FormatTerminal
 	}
 	ctx := log.Context(context.Background(), log.WithFormat(format), log.WithFunc(trace.Log))
-	ctx = log.With(ctx, log.KV{"svc", genforecaster.ServiceName})
+	ctx = log.With(ctx, log.KV{K: "svc", V: genforecaster.ServiceName})
 	if *debugf {
 		ctx = log.Context(ctx, log.WithDebug())
 		log.Debugf(ctx, "debug logs enabled")
@@ -83,7 +82,7 @@ func main() {
 	// 6. Create transport
 	server := gengrpc.New(endpoints, nil)
 	grpcsvr := grpc.NewServer(
-		grpcmiddleware.WithUnaryServerChain(
+		grpc.ChainUnaryInterceptor(
 			goagrpcmiddleware.UnaryRequestID(),
 			log.UnaryServerInterceptor(ctx),
 			debug.UnaryServerInterceptor(),
@@ -95,7 +94,7 @@ func main() {
 	reflection.Register(grpcsvr)
 	for svc, info := range grpcsvr.GetServiceInfo() {
 		for _, m := range info.Methods {
-			log.Print(ctx, log.KV{"method", svc + "/" + m.Name})
+			log.Print(ctx, log.KV{K: "method", V: svc + "/" + m.Name})
 		}
 	}
 
@@ -147,7 +146,9 @@ func main() {
 		defer cancel()
 
 		grpcsvr.GracefulStop()
-		httpsvr.Shutdown(ctx)
+		if err := httpsvr.Shutdown(ctx); err != nil {
+			log.Errorf(ctx, err, "failed to shutdown HTTP server")
+		}
 	}()
 
 	// Cleanup

example/weather/services/front/clients/forecaster/client.go

@@ -69,7 +69,7 @@ func New(cc *grpc.ClientConn) Client {
 // Forecast returns the forecast for the given location or current location if
 // lat or long are nil.
 func (c *client) GetForecast(ctx context.Context, lat, long float64) (*Forecast, error) {
-	res, err := c.forecast(ctx, &genforecast.ForecastPayload{lat, long})
+	res, err := c.forecast(ctx, &genforecast.ForecastPayload{Lat: lat, Long: long})
 	if err != nil {
 		return nil, err
 	}

example/weather/services/front/cmd/front/main.go

@@ -161,8 +161,12 @@ func main() {
 		ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second)
 		defer cancel()
 
-		httpServer.Shutdown(ctx)
-		metricsServer.Shutdown(ctx)
+		if err := httpServer.Shutdown(ctx); err != nil {
+			log.Errorf(ctx, err, "failed to shutdown HTTP server")
+		}
+		if err := metricsServer.Shutdown(ctx); err != nil {
+			log.Errorf(ctx, err, "failed to shutdown metrics server")
+		}
 	}()
 
 	// Cleanup

example/weather/services/locator/cmd/locator/main.go

@@ -12,7 +12,6 @@ import (
 	"syscall"
 	"time"
 
-	grpcmiddleware "github.com/grpc-ecosystem/go-grpc-middleware"
 	"goa.design/clue/debug"
 	"goa.design/clue/health"
 	"goa.design/clue/log"
@@ -45,7 +44,7 @@ func main() {
 		format = log.FormatTerminal
 	}
 	ctx := log.Context(context.Background(), log.WithFormat(format), log.WithFunc(trace.Log))
-	ctx = log.With(ctx, log.KV{"svc", genlocator.ServiceName})
+	ctx = log.With(ctx, log.KV{K: "svc", V: genlocator.ServiceName})
 	if *debugf {
 		ctx = log.Context(ctx, log.WithDebug())
 		log.Debugf(ctx, "debug logs enabled")
@@ -83,7 +82,7 @@ func main() {
 	// 6. Create transport
 	server := gengrpc.New(endpoints, nil)
 	grpcsvr := grpc.NewServer(
-		grpcmiddleware.WithUnaryServerChain(
+		grpc.ChainUnaryInterceptor(
 			goagrpcmiddleware.UnaryRequestID(),
 			log.UnaryServerInterceptor(ctx),
 			debug.UnaryServerInterceptor(),
@@ -95,7 +94,7 @@ func main() {
 	reflection.Register(grpcsvr)
 	for svc, info := range grpcsvr.GetServiceInfo() {
 		for _, m := range info.Methods {
-			log.Print(ctx, log.KV{"method", svc + "/" + m.Name})
+			log.Print(ctx, log.KV{K: "method", V: svc + "/" + m.Name})
 		}
 	}
 
@@ -147,7 +146,9 @@ func main() {
 		defer cancel()
 
 		grpcsvr.GracefulStop()
-		httpsvr.Shutdown(ctx)
+		if err := httpsvr.Shutdown(ctx); err != nil {
+			log.Errorf(ctx, err, "failed to shutdown HTTP server")
+		}
 	}()
 
 	// Cleanup

example/weather/services/locator/locator_test.go

@@ -21,7 +21,7 @@ func TestGetIPLocation(t *testing.T) {
 	// location then failing.
 	ipc := mockipapi.NewClient(t)
 	ipc.AddGetLocation(func(ctx context.Context, ip string) (*ipapi.WorldLocation, error) {
-		return &ipapi.WorldLocation{testLat, testLong, testCity, testRegion, testCountry}, nil
+		return &ipapi.WorldLocation{Lat: testLat, Long: testLong, City: testCity, Region: testRegion, Country: testCountry}, nil
 	})
 	ipc.AddGetLocation(func(ctx context.Context, ip string) (*ipapi.WorldLocation, error) {
 		return nil, fmt.Errorf("test failure")

health/handler.go

@@ -18,6 +18,6 @@ func Handler(chk Checker) http.HandlerFunc {
 		} else {
 			w.WriteHeader(http.StatusServiceUnavailable)
 		}
-		w.Write(b)
+		w.Write(b) // nolint: errcheck
 	})
 }

internal/testsvc/grpc_testing.go

@@ -59,7 +59,7 @@ func SetupGRPC(t *testing.T, opts ...GRPCOption) (c GRPClient, stop func()) {
 	if err != nil {
 		t.Fatal(err)
 	}
-	go server.Serve(l)
+	go server.Serve(l) // nolint: errcheck
 
 	// Connect to in-memory server
 	dialOptions := append(options.dialOptions, grpc.WithTransportCredentials(insecure.NewCredentials()))

log/adapt_test.go

@@ -18,7 +18,7 @@ func TestAsGoaMiddlwareLogger(t *testing.T) {
 	var buf bytes.Buffer
 	ctx := Context(context.Background(), WithOutput(&buf))
 	logger := AsGoaMiddlewareLogger(ctx)
-	logger.Log("msg", "hello world")
+	assert.NoError(t, logger.Log("msg", "hello world"))
 	want := "time=2022-01-09T20:29:45Z level=info msg=\"hello world\"\n"
 	assert.Equal(t, buf.String(), want)
 }

log/format.go

@@ -27,7 +27,7 @@ var TimestampFormatLayout = time.RFC3339
 // FormatText is the default log formatter when not running in a terminal, it
 // prints entries using the logfmt format:
 //
-//    time=TIME level=SEVERITY KEY=VAL KEY=VAL ...
+//	time=TIME level=SEVERITY KEY=VAL KEY=VAL ...
 //
 // Where TIME is the UTC timestamp in RFC3339 format, SEVERITY is one of
 // "debug", "info" or "error", and KEY=VAL are the entry key/value pairs.
@@ -38,8 +38,8 @@ var TimestampFormatLayout = time.RFC3339
 func FormatText(e *Entry) []byte {
 	var b bytes.Buffer
 	enc := logfmt.NewEncoder(&b)
-	enc.EncodeKeyval(TimestampKey, e.Time.Format(TimestampFormatLayout))
-	enc.EncodeKeyval(SeverityKey, e.Severity)
+	enc.EncodeKeyval(TimestampKey, e.Time.Format(TimestampFormatLayout)) // nolint: errcheck
+	enc.EncodeKeyval(SeverityKey, e.Severity)                            // nolint: errcheck
 	for _, kv := range e.KeyVals {
 		// Make logfmt format slices
 		v := kv.V
@@ -49,7 +49,7 @@ func FormatText(e *Entry) []byte {
 			writeJSON(kv.V, &buf)
 			v = buf.String()
 		}
-		enc.EncodeKeyval(kv.K, v)
+		enc.EncodeKeyval(kv.K, v) // nolint: errcheck
 	}
 	b.WriteByte('\n')
 	return b.Bytes()
@@ -58,13 +58,13 @@ func FormatText(e *Entry) []byte {
 // FormatJSON is a log formatter that prints entries using JSON. Entries are
 // formatted as follows:
 //
-//   {
-//     "time": "TIMESTAMP", // UTC timestamp in RFC3339 format
-//     "level": "SEVERITY", // one of DEBUG, INFO or ERROR
-//     "key1": "val1",      // entry key/value pairs
-//     "key2": "val2",
-//     ...
-//   }
+//	{
+//	  "time": "TIMESTAMP", // UTC timestamp in RFC3339 format
+//	  "level": "SEVERITY", // one of DEBUG, INFO or ERROR
+//	  "key1": "val1",      // entry key/value pairs
+//	  "key2": "val2",
+//	  ...
+//	}
 //
 // note: the implementation avoids using reflection (and thus the json package)
 // for efficiency.
@@ -101,7 +101,7 @@ func FormatJSON(e *Entry) []byte {
 // FormatTerminal is a log formatter that prints entries suitable for terminal
 // that supports colors. It prints entries in the following format:
 //
-//    SEVERITY[seconds] key=val key=val ...
+//	SEVERITY[seconds] key=val key=val ...
 //
 // Where SEVERITY is one of DEBG, INFO or ERRO, seconds is the number of seconds
 // since the application started, message is the log message, and key=val are