add access log to api and debug api http handlers

pkg/api/pingpong.go

@@ -25,11 +25,11 @@ func (s *server) pingpongHandler(w http.ResponseWriter, r *http.Request) {
 	rtt, err := s.Pingpong.Ping(ctx, peerID, "hey", "there", ",", "how are", "you", "?")
 	if err != nil {
 		if errors.Is(err, p2p.ErrPeerNotFound) {
-			s.Logger.Debugf("pingpong: ping %s: %w", peerID, err)
+			s.Logger.Debugf("pingpong: ping %s: %v", peerID, err)
 			jsonhttp.NotFound(w, "peer not found")
 			return
 		}
-		s.Logger.Errorf("pingpong: ping %s: %w", peerID, err)
+		s.Logger.Errorf("pingpong: ping %s: %v", peerID, err)
 		jsonhttp.InternalServerError(w, err)
 		return
 	}

pkg/api/router.go

@@ -9,8 +9,10 @@ import (
 	"net/http"
 
 	"github.com/ethersphere/bee/pkg/jsonhttp"
+	"github.com/ethersphere/bee/pkg/logging"
 	"github.com/gorilla/handlers"
 	"github.com/gorilla/mux"
+	"github.com/sirupsen/logrus"
 	"resenje.org/web"
 )
 
@@ -26,6 +28,7 @@ func (s *server) setupRouting() {
 	})
 
 	s.Handler = web.ChainHandlers(
+		logging.NewHTTPAccessLogHandler(s.Logger, logrus.InfoLevel, "api access"),
 		handlers.CompressHandler,
 		s.pageviewMetricsHandler,
 		web.FinalHandler(baseRouter),

pkg/debugapi/peer.go

@@ -19,14 +19,14 @@ type peerConnectResponse struct {
 func (s *server) peerConnectHandler(w http.ResponseWriter, r *http.Request) {
 	addr, err := multiaddr.NewMultiaddr("/" + mux.Vars(r)["multi-address"])
 	if err != nil {
-		s.Logger.Debugf("debug api: peer connect: parse multiaddress: %w", err)
+		s.Logger.Debugf("debug api: peer connect: parse multiaddress: %v", err)
 		jsonhttp.BadRequest(w, err)
 		return
 	}
 
 	address, err := s.P2P.Connect(r.Context(), addr)
 	if err != nil {
-		s.Logger.Errorf("debug api: peer connect: %w", err)
+		s.Logger.Errorf("debug api: peer connect: %v", err)
 		jsonhttp.InternalServerError(w, err)
 		return
 	}

pkg/debugapi/router.go

@@ -10,9 +10,11 @@ import (
 	"net/http/pprof"
 
 	"github.com/ethersphere/bee/pkg/jsonhttp"
+	"github.com/ethersphere/bee/pkg/logging"
 	"github.com/gorilla/handlers"
 	"github.com/gorilla/mux"
 	"github.com/prometheus/client_golang/prometheus/promhttp"
+	"github.com/sirupsen/logrus"
 	"resenje.org/web"
 )
 
@@ -26,6 +28,7 @@ func (s *server) setupRouting() {
 
 	internalRouter := mux.NewRouter()
 	internalBaseRouter.Handle("/", web.ChainHandlers(
+		logging.NewHTTPAccessLogHandler(s.Logger, logrus.InfoLevel, "debug api access"),
 		handlers.CompressHandler,
 		web.NoCacheHeadersHandler,
 		web.FinalHandler(internalRouter),

pkg/logging/http_access.go

+// Copyright 2020 The Swarm Authors. All rights reserved.
+// Use of this source code is governed by a BSD-style
+// license that can be found in the LICENSE file.
+
+package logging
+
+import (
+	"net"
+	"net/http"
+	"time"
+
+	"github.com/sirupsen/logrus"
+)
+
+func NewHTTPAccessLogHandler(logger Logger, level logrus.Level, message string) func(h http.Handler) http.Handler {
+	return func(h http.Handler) http.Handler {
+		return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
+			startTime := time.Now()
+			rl := &responseLogger{w, 0, 0}
+
+			h.ServeHTTP(rl, r)
+
+			status := rl.status
+			if status == 0 {
+				status = http.StatusOK
+			}
+			ip, _, err := net.SplitHostPort(r.RemoteAddr)
+			if err != nil {
+				ip = r.RemoteAddr
+			}
+			fields := logrus.Fields{
+				"ip":       ip,
+				"method":   r.Method,
+				"uri":      r.RequestURI,
+				"proto":    r.Proto,
+				"status":   status,
+				"size":     rl.size,
+				"duration": time.Since(startTime).Seconds(),
+			}
+			if v := r.Referer(); v != "" {
+				fields["referrer"] = v
+			}
+			if v := r.UserAgent(); v != "" {
+				fields["user-agent"] = v
+			}
+			if v := r.Header.Get("X-Forwarded-For"); v != "" {
+				fields["x-forwarded-for"] = v
+			}
+			if v := r.Header.Get("X-Real-Ip"); v != "" {
+				fields["x-real-ip"] = v
+			}
+			logger.WithFields(fields).Log(level, message)
+		})
+	}
+}
+
+type responseLogger struct {
+	w      http.ResponseWriter
+	status int
+	size   int
+}
+
+func (l *responseLogger) Header() http.Header {
+	return l.w.Header()
+}
+
+func (l *responseLogger) Flush() {
+	l.w.(http.Flusher).Flush()
+}
+
+func (l *responseLogger) Push(target string, opts *http.PushOptions) error {
+	return l.w.(http.Pusher).Push(target, opts)
+}
+
+func (l *responseLogger) Write(b []byte) (int, error) {
+	size, err := l.w.Write(b)
+	l.size += size
+	return size, err
+}
+
+func (l *responseLogger) WriteHeader(s int) {
+	l.w.WriteHeader(s)
+	if l.status == 0 {
+		l.status = s
+	}
+}

pkg/logging/logging.go

@@ -22,6 +22,9 @@ type Logger interface {
 	Errorf(format string, args ...interface{})
 	Error(args ...interface{})
 	SetOutput(io.Writer)
+	SetLevel(logrus.Level)
+	WithField(key string, value interface{}) *logrus.Entry
+	WithFields(fields logrus.Fields) *logrus.Entry
 }
 
 func New(w io.Writer) Logger {

pkg/node/node.go

@@ -78,6 +78,7 @@ func NewBee(o Options) (*Bee, error) {
 		// API server
 		apiService = api.New(api.Options{
 			Pingpong: pingPong,
+			Logger:   logger,
 		})
 		apiListener, err := net.Listen("tcp", o.APIAddr)
 		if err != nil {
@@ -103,7 +104,8 @@ func NewBee(o Options) (*Bee, error) {
 	if o.DebugAPIAddr != "" {
 		// Debug API server
 		debugAPIService := debugapi.New(debugapi.Options{
-			P2P: p2ps,
+			P2P:    p2ps,
+			Logger: logger,
 		})
 		// register metrics from components
 		debugAPIService.MustRegisterMetrics(p2ps.Metrics()...)