Adds tests on logger middleware

logger.go

@@ -11,11 +11,16 @@ import (
 )
 
 const (
-	remoteAddr = "addr"
-	reqLength  = "req_size"
-	respLength = "resp_size"
-	latency    = "latency"
-	hostname   = "server"
+	// LogRemoteAddr is the name of the log's field for the remote address.
+	LogRemoteAddr = "addr"
+	// LogRequestSize is the name of the log's field for the request size.
+	LogRequestSize = "req_size"
+	// LogResponseSize is the name of the log's field for the response size.
+	LogResponseSize = "resp_size"
+	// LogLatency is the name of the log's field with the response duration.
+	LogLatency = "latency"
+	// LogServerHostname is the name of the log's field with the server hostname.
+	LogServerHostname = "server"
 )
 
 // Logger returns a middleware to log each TCP request.
@@ -61,25 +66,32 @@ type message struct {
 
 func (m *message) fields(w ResponseWriter, f logrus.Fields) logrus.Fields {
 	d := make(logrus.Fields)
-	for k := range f {
+	for k, v := range f {
 		switch k {
-		case remoteAddr:
+		case LogRemoteAddr:
 			d[k] = m.req.RemoteAddr
-		case reqLength:
-			d[k] = w.Size()
-		case respLength:
+		case LogRequestSize:
 			d[k] = m.reqSize
-		case latency:
+		case LogResponseSize:
+			d[k] = w.Size()
+		case LogLatency:
 			m.latency = time.Since(m.start)
-			d[k] = int(math.Ceil(float64(m.latency.Nanoseconds()) / 1000.0))
-		case hostname:
+			d[k] = int(math.Ceil(float64(m.latency.Nanoseconds()) / float64(time.Millisecond)))
+		case LogServerHostname:
 			d[k], _ = os.Hostname()
+		default:
+			// allows to logs statics data
+			d[k] = v
 		}
 	}
 	return d
 }
 
 // String implements the fmt.Stringer interface.
 func (m *message) String() string {
+	if m.req == nil {
+		// unexpected segment
+		return ""
+	}
 	return "[TCP] " + m.start.Format(time.RFC3339) + " | " + m.req.Segment
 }

logger_internal_test.go

@@ -0,0 +1,22 @@
+package tcp
+
+import (
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/matryer/is"
+)
+
+func TestMessage_String(t *testing.T) {
+	const blog = "[TCP] 0001-01-01T00:00:00Z | ACK"
+	msg := &message{}
+	req := NewRequest(ACK, nil)
+	are := is.New(t)
+	are.True(msg.String() == "") // invalid request
+	msg.req = req
+	are.Equal(msg.String(), blog) // invalid starting date
+	msg = newMessage(req)
+	are.True(strings.HasSuffix(msg.String(), ACK))
+	are.True(strings.Contains(msg.String(), time.Now().UTC().Format("2006-01-02T15:04")))
+}

logger_test.go

@@ -1 +1,121 @@
-package tcp
+package tcp_test
+
+import (
+	"errors"
+	"io"
+	"strconv"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/matryer/is"
+
+	"github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus/hooks/test"
+
+	"github.com/rvflash/tcp"
+)
+
+var (
+	defaultFields = logrus.Fields{
+		tcp.LogLatency:        0,
+		tcp.LogServerHostname: "",
+		tcp.LogRemoteAddr:     "",
+		tcp.LogRequestSize:    0,
+		tcp.LogResponseSize:   0,
+	}
+	customFields = logrus.Fields{
+		tcp.LogLatency:     0,
+		tcp.LogRequestSize: 0,
+		vField:             vValue,
+	}
+	vField = "version"
+	vValue = "v0.0.0"
+)
+
+func TestLogger(t *testing.T) {
+	var (
+		are = is.New(t)
+		dt  = []struct {
+			body io.Reader
+			bodySize,
+			dataSize int
+			fields      logrus.Fields
+			handler     []tcp.HandlerFunc
+			level       logrus.Level
+			minDuration int
+		}{
+			{
+				body:     strings.NewReader("hello world"),
+				bodySize: 11,
+				dataSize: 5,
+				fields:   defaultFields,
+				level:    logrus.InfoLevel,
+			},
+			{
+				dataSize: 5,
+				fields:   defaultFields,
+				handler:  []tcp.HandlerFunc{stumble},
+				level:    logrus.WarnLevel,
+			},
+			{
+				dataSize:    5,
+				fields:      defaultFields,
+				handler:     []tcp.HandlerFunc{sleep},
+				level:       logrus.InfoLevel,
+				minDuration: 100,
+			},
+			{
+				dataSize:    3,
+				fields:      customFields,
+				handler:     []tcp.HandlerFunc{stumble, sleep},
+				level:       logrus.WarnLevel,
+				minDuration: 100,
+			},
+			{
+				dataSize: 3,
+				fields:   customFields,
+				handler:  []tcp.HandlerFunc{oops},
+				level:    logrus.ErrorLevel,
+			},
+		}
+
+		entry *logrus.Entry
+		v     interface{}
+		ok    bool
+	)
+
+	log, hook := test.NewNullLogger()
+	log.Formatter = &logrus.TextFormatter{DisableTimestamp: true}
+
+	for i, tt := range dt {
+		t.Run("#"+strconv.Itoa(i), func(t *testing.T) {
+			// launches the server
+			srv := tcp.New()
+			srv.Use(tcp.Logger(log, tt.fields))
+			srv.Use(tcp.Recovery())
+			srv.SYN(tt.handler...)
+			// serves the request
+			srv.ServeTCP(tcp.NewRecorder(), tcp.NewRequest(tcp.SYN, tt.body))
+			// checks the log's message
+			entry = hook.LastEntry()
+			are.Equal(entry.Level, tt.level)                            // level mismatch
+			are.Equal(len(entry.Data), tt.dataSize)                     // fields size mismatch
+			are.True(entry.Data[tcp.LogLatency].(int) > tt.minDuration) // min duration
+			if _, ok = tt.fields[vField]; ok {
+				v, ok = entry.Data[vField]
+				are.True(ok)         // version required
+				are.Equal(v, vValue) // version mismatch
+			}
+			are.Equal(entry.Data[tcp.LogRequestSize].(int), tt.bodySize) //  request size mismatch
+		})
+	}
+}
+
+func sleep(_ *tcp.Context) {
+	time.Sleep(time.Millisecond * 100)
+}
+
+func stumble(c *tcp.Context) {
+	c.Error(errors.New("my bad, sorry!"))
+}

request.go

@@ -12,7 +12,7 @@ type Request struct {
 	Segment string
 	// Body is the request's body.
 	Body io.ReadCloser
-	// remoteAddr returns the remote network address.
+	// LogRemoteAddr returns the remote network address.
 	RemoteAddr string
 
 	// Context of the request.

server.go

@@ -43,11 +43,11 @@ const (
 // Default returns an instance of TCP server with a Logger and a Recover on panic attached.
 func Default() *Server {
 	f := logrus.Fields{
-		latency:    0,
-		hostname:   "",
-		remoteAddr: "",
-		reqLength:  0,
-		respLength: 0,
+		LogLatency:        0,
+		LogServerHostname: "",
+		LogRemoteAddr:     "",
+		LogRequestSize:    0,
+		LogResponseSize:   0,
 	}
 	l := logrus.New()
 	l.Formatter = &logrus.TextFormatter{DisableTimestamp: true}