Create logger package and rename errorIf to LogIf (#5678)

Removing message from error logging Replace errors.Trace with LogIf
2026-07-19 20:20:25 +03:00 · 2018-04-05 15:04:40 -07:00
parent 91fd8ffeb7
commit f8a3fd0c2a
119 changed files with 2608 additions and 1860 deletions
@@ -17,8 +17,8 @@
 package http

 import (
+	"context"
 	"crypto/tls"
-	"errors"
 	"fmt"
 	"io"
 	"net"
@@ -28,6 +28,8 @@ import (
 	"sync"
 	"syscall"
 	"time"
+
+	"github.com/minio/minio/cmd/logger"
 )

 var sslRequiredErrMsg = []byte("HTTP/1.0 403 Forbidden\r\n\r\nSSL required")
@@ -85,9 +87,8 @@ type httpListener struct {
 	tcpKeepAliveTimeout    time.Duration
 	readTimeout            time.Duration
 	writeTimeout           time.Duration
-	updateBytesReadFunc    func(int)                           // function to be called to update bytes read in BufConn.
-	updateBytesWrittenFunc func(int)                           // function to be called to update bytes written in BufConn.
-	errorLogFunc           func(error, string, ...interface{}) // function to be called on errors.
+	updateBytesReadFunc    func(int) // function to be called to update bytes read in BufConn.
+	updateBytesWrittenFunc func(int) // function to be called to update bytes written in BufConn.
 }

 // isRoutineNetErr returns true if error is due to a network timeout,
@@ -139,17 +140,16 @@ func (listener *httpListener) start() {
 		// Peek bytes of maximum length of all HTTP methods.
 		data, err := bufconn.Peek(methodMaxLen)
 		if err != nil {
-			if listener.errorLogFunc != nil {
-				// Peek could fail legitimately when clients abruptly close
-				// connection. E.g. Chrome browser opens connections speculatively to
-				// speed up loading of a web page. Peek may also fail due to network
-				// saturation on a transport with read timeout set. All other kind of
-				// errors should be logged for further investigation. Thanks @brendanashworth.
-				if !isRoutineNetErr(err) {
-					listener.errorLogFunc(err,
-						"Error in reading from new connection %s at server %s",
-						bufconn.RemoteAddr(), bufconn.LocalAddr())
-				}
+			// Peek could fail legitimately when clients abruptly close
+			// connection. E.g. Chrome browser opens connections speculatively to
+			// speed up loading of a web page. Peek may also fail due to network
+			// saturation on a transport with read timeout set. All other kind of
+			// errors should be logged for further investigation. Thanks @brendanashworth.
+			if !isRoutineNetErr(err) {
+				reqInfo := (&logger.ReqInfo{}).AppendTags("remoteAddr", bufconn.RemoteAddr().String())
+				reqInfo.AppendTags("localAddr", bufconn.LocalAddr().String())
+				ctx := logger.SetReqInfo(context.Background(), reqInfo)
+				logger.LogIf(ctx, err)
 			}
 			bufconn.Close()
 			return
@@ -172,12 +172,11 @@ func (listener *httpListener) start() {
 		if listener.tlsConfig != nil {
 			// As the listener is configured with TLS, try to do TLS handshake, drop the connection if it fails.
 			tlsConn := tls.Server(bufconn, listener.tlsConfig)
-			if err := tlsConn.Handshake(); err != nil {
-				if listener.errorLogFunc != nil {
-					listener.errorLogFunc(err,
-						"TLS handshake failed with new connection %s at server %s",
-						bufconn.RemoteAddr(), bufconn.LocalAddr())
-				}
+			if err = tlsConn.Handshake(); err != nil {
+				reqInfo := (&logger.ReqInfo{}).AppendTags("remoteAddr", bufconn.RemoteAddr().String())
+				reqInfo.AppendTags("localAddr", bufconn.LocalAddr().String())
+				ctx := logger.SetReqInfo(context.Background(), reqInfo)
+				logger.LogIf(ctx, err)
 				bufconn.Close()
 				return
 			}
@@ -187,12 +186,13 @@ func (listener *httpListener) start() {
 				listener.updateBytesReadFunc, listener.updateBytesWrittenFunc)

 			// Peek bytes of maximum length of all HTTP methods.
-			data, err := bufconn.Peek(methodMaxLen)
+			data, err = bufconn.Peek(methodMaxLen)
 			if err != nil {
-				if !isRoutineNetErr(err) && listener.errorLogFunc != nil {
-					listener.errorLogFunc(err,
-						"Error in reading from new TLS connection %s at server %s",
-						bufconn.RemoteAddr(), bufconn.LocalAddr())
+				if !isRoutineNetErr(err) {
+					reqInfo := (&logger.ReqInfo{}).AppendTags("remoteAddr", bufconn.RemoteAddr().String())
+					reqInfo.AppendTags("localAddr", bufconn.LocalAddr().String())
+					ctx := logger.SetReqInfo(context.Background(), reqInfo)
+					logger.LogIf(ctx, err)
 				}
 				bufconn.Close()
 				return
@@ -205,12 +205,10 @@ func (listener *httpListener) start() {
 				return
 			}
 		}
-
-		if listener.errorLogFunc != nil {
-			listener.errorLogFunc(errors.New("junk message"),
-				"Received non-HTTP message from new connection %s at server %s",
-				bufconn.RemoteAddr(), bufconn.LocalAddr())
-		}
+		reqInfo := (&logger.ReqInfo{}).AppendTags("remoteAddr", bufconn.RemoteAddr().String())
+		reqInfo.AppendTags("localAddr", bufconn.LocalAddr().String())
+		ctx := logger.SetReqInfo(context.Background(), reqInfo)
+		logger.LogIf(ctx, err)

 		bufconn.Close()
 		return
@@ -299,8 +297,7 @@ func newHTTPListener(serverAddrs []string,
 	readTimeout time.Duration,
 	writeTimeout time.Duration,
 	updateBytesReadFunc func(int),
-	updateBytesWrittenFunc func(int),
-	errorLogFunc func(error, string, ...interface{})) (listener *httpListener, err error) {
+	updateBytesWrittenFunc func(int)) (listener *httpListener, err error) {

 	var tcpListeners []*net.TCPListener
 	// Close all opened listeners on error
@@ -337,7 +334,6 @@ func newHTTPListener(serverAddrs []string,
 		writeTimeout:           writeTimeout,
 		updateBytesReadFunc:    updateBytesReadFunc,
 		updateBytesWrittenFunc: updateBytesWrittenFunc,
-		errorLogFunc:           errorLogFunc,
 	}
 	listener.start()

@@ -19,6 +19,7 @@ package http
 import (
 	"bufio"
 	"bytes"
+	"context"
 	"crypto/tls"
 	"errors"
 	"fmt"
@@ -205,7 +206,7 @@ func TestNewHTTPListener(t *testing.T) {
 		writeTimeout           time.Duration
 		updateBytesReadFunc    func(int)
 		updateBytesWrittenFunc func(int)
-		errorLogFunc           func(error, string, ...interface{})
+		errorLogFunc           func(context.Context, error)
 		expectedErr            error
 	}{
 		{[]string{"93.184.216.34:65432"}, nil, time.Duration(0), time.Duration(0), time.Duration(0), nil, nil, nil, errors.New(remoteAddrErrMsg)},
@@ -227,7 +228,6 @@ func TestNewHTTPListener(t *testing.T) {
 			testCase.writeTimeout,
 			testCase.updateBytesReadFunc,
 			testCase.updateBytesWrittenFunc,
-			testCase.errorLogFunc,
 		)

 		if testCase.expectedErr == nil {
@@ -279,7 +279,6 @@ func TestHTTPListenerStartClose(t *testing.T) {
 			time.Duration(0),
 			nil,
 			nil,
-			nil,
 		)
 		if err != nil {
 			t.Fatalf("Test %d: error: expected = <nil>, got = %v", i+1, err)
@@ -327,7 +326,6 @@ func TestHTTPListenerAddr(t *testing.T) {
 			time.Duration(0),
 			nil,
 			nil,
-			nil,
 		)
 		if err != nil {
 			t.Fatalf("Test %d: error: expected = <nil>, got = %v", i+1, err)
@@ -372,7 +370,6 @@ func TestHTTPListenerAddrs(t *testing.T) {
 			time.Duration(0),
 			nil,
 			nil,
-			nil,
 		)
 		if err != nil {
 			t.Fatalf("Test %d: error: expected = <nil>, got = %v", i+1, err)
@@ -419,7 +416,6 @@ func TestHTTPListenerAccept(t *testing.T) {
 			time.Duration(0),
 			nil,
 			nil,
-			nil,
 		)
 		if err != nil {
 			t.Fatalf("Test %d: error: expected = <nil>, got = %v", i+1, err)
@@ -480,11 +476,6 @@ func TestHTTPListenerAccept(t *testing.T) {
 func TestHTTPListenerAcceptPeekError(t *testing.T) {
 	tlsConfig := getTLSConfig(t)
 	nonLoopBackIP := getNonLoopBackIP(t)
-	errorFunc := func(err error, template string, args ...interface{}) {
-		msg := fmt.Sprintf("error: %v.  ", err)
-		msg += fmt.Sprintf(template, args...)
-		fmt.Println(msg)
-	}

 	testCases := []struct {
 		serverAddrs []string
@@ -504,7 +495,6 @@ func TestHTTPListenerAcceptPeekError(t *testing.T) {
 			time.Duration(0),
 			nil,
 			nil,
-			errorFunc,
 		)
 		if err != nil {
 			t.Fatalf("Test %d: error: expected = <nil>, got = %v", i+1, err)
@@ -540,11 +530,6 @@ func TestHTTPListenerAcceptPeekError(t *testing.T) {
 func TestHTTPListenerAcceptTLSError(t *testing.T) {
 	tlsConfig := getTLSConfig(t)
 	nonLoopBackIP := getNonLoopBackIP(t)
-	errorFunc := func(err error, template string, args ...interface{}) {
-		msg := fmt.Sprintf("error: %v.  ", err)
-		msg += fmt.Sprintf(template, args...)
-		fmt.Println(msg)
-	}

 	testCases := []struct {
 		serverAddrs []string
@@ -563,7 +548,6 @@ func TestHTTPListenerAcceptTLSError(t *testing.T) {
 			time.Duration(0),
 			nil,
 			nil,
-			errorFunc,
 		)
 		if err != nil {
 			t.Fatalf("Test %d: error: expected = <nil>, got = %v", i+1, err)
@@ -609,11 +593,6 @@ func TestHTTPListenerAcceptTLSError(t *testing.T) {
 func TestHTTPListenerAcceptError(t *testing.T) {
 	tlsConfig := getTLSConfig(t)
 	nonLoopBackIP := getNonLoopBackIP(t)
-	errorFunc := func(err error, template string, args ...interface{}) {
-		msg := fmt.Sprintf("error: %v.  ", err)
-		msg += fmt.Sprintf(template, args...)
-		fmt.Println(msg)
-	}

 	testCases := []struct {
 		serverAddrs  []string
@@ -635,7 +614,6 @@ func TestHTTPListenerAcceptError(t *testing.T) {
 			time.Duration(0),
 			nil,
 			nil,
-			errorFunc,
 		)
 		if err != nil {
 			t.Fatalf("Test %d: error: expected = <nil>, got = %v", i+1, err)
@@ -761,7 +739,6 @@ func TestHTTPListenerAcceptParallel(t *testing.T) {
 			time.Duration(0),
 			nil,
 			nil,
-			nil,
 		)
 		if err != nil {
 			t.Fatalf("Test %d: error: expected = <nil>, got = %v", i+1, err)
@@ -50,16 +50,15 @@ const (
 // Server - extended http.Server supports multiple addresses to serve and enhanced connection handling.
 type Server struct {
 	http.Server
-	Addrs                  []string                            // addresses on which the server listens for new connection.
-	ShutdownTimeout        time.Duration                       // timeout used for graceful server shutdown.
-	TCPKeepAliveTimeout    time.Duration                       // timeout used for underneath TCP connection.
-	UpdateBytesReadFunc    func(int)                           // function to be called to update bytes read in bufConn.
-	UpdateBytesWrittenFunc func(int)                           // function to be called to update bytes written in bufConn.
-	ErrorLogFunc           func(error, string, ...interface{}) // function to be called on errors.
-	listenerMutex          *sync.Mutex                         // to guard 'listener' field.
-	listener               *httpListener                       // HTTP listener for all 'Addrs' field.
-	inShutdown             uint32                              // indicates whether the server is in shutdown or not
-	requestCount           int32                               // counter holds no. of request in process.
+	Addrs                  []string      // addresses on which the server listens for new connection.
+	ShutdownTimeout        time.Duration // timeout used for graceful server shutdown.
+	TCPKeepAliveTimeout    time.Duration // timeout used for underneath TCP connection.
+	UpdateBytesReadFunc    func(int)     // function to be called to update bytes read in bufConn.
+	UpdateBytesWrittenFunc func(int)     // function to be called to update bytes written in bufConn.
+	listenerMutex          *sync.Mutex   // to guard 'listener' field.
+	listener               *httpListener // HTTP listener for all 'Addrs' field.
+	inShutdown             uint32        // indicates whether the server is in shutdown or not
+	requestCount           int32         // counter holds no. of request in process.
 }

 // Start - start HTTP server
@@ -77,7 +76,6 @@ func (srv *Server) Start() (err error) {
 	tcpKeepAliveTimeout := srv.TCPKeepAliveTimeout
 	updateBytesReadFunc := srv.UpdateBytesReadFunc
 	updateBytesWrittenFunc := srv.UpdateBytesWrittenFunc
-	errorLogFunc := srv.ErrorLogFunc // if srv.ErrorLogFunc holds non-synced state -> possible data race

 	// Create new HTTP listener.
 	var listener *httpListener
@@ -89,7 +87,6 @@ func (srv *Server) Start() (err error) {
 		writeTimeout,
 		updateBytesReadFunc,
 		updateBytesWrittenFunc,
-		errorLogFunc,
 	)
 	if err != nil {
 		return err