logger_test.go

Documentation: github.com/gin-gonic/gin

     1  // Copyright 2014 Manu Martinez-Almeida. All rights reserved.
     2  // Use of this source code is governed by a MIT style
     3  // license that can be found in the LICENSE file.
     4  
     5  package gin
     6  
     7  import (
     8  	"errors"
     9  	"fmt"
    10  	"net/http"
    11  	"strings"
    12  	"testing"
    13  	"time"
    14  
    15  	"github.com/stretchr/testify/assert"
    16  )
    17  
    18  func init() {
    19  	SetMode(TestMode)
    20  }
    21  
    22  func TestLogger(t *testing.T) {
    23  	buffer := new(strings.Builder)
    24  	router := New()
    25  	router.Use(LoggerWithWriter(buffer))
    26  	router.GET("/example", func(c *Context) {})
    27  	router.POST("/example", func(c *Context) {})
    28  	router.PUT("/example", func(c *Context) {})
    29  	router.DELETE("/example", func(c *Context) {})
    30  	router.PATCH("/example", func(c *Context) {})
    31  	router.HEAD("/example", func(c *Context) {})
    32  	router.OPTIONS("/example", func(c *Context) {})
    33  
    34  	PerformRequest(router, "GET", "/example?a=100")
    35  	assert.Contains(t, buffer.String(), "200")
    36  	assert.Contains(t, buffer.String(), "GET")
    37  	assert.Contains(t, buffer.String(), "/example")
    38  	assert.Contains(t, buffer.String(), "a=100")
    39  
    40  	// I wrote these first (extending the above) but then realized they are more
    41  	// like integration tests because they test the whole logging process rather
    42  	// than individual functions.  Im not sure where these should go.
    43  	buffer.Reset()
    44  	PerformRequest(router, "POST", "/example")
    45  	assert.Contains(t, buffer.String(), "200")
    46  	assert.Contains(t, buffer.String(), "POST")
    47  	assert.Contains(t, buffer.String(), "/example")
    48  
    49  	buffer.Reset()
    50  	PerformRequest(router, "PUT", "/example")
    51  	assert.Contains(t, buffer.String(), "200")
    52  	assert.Contains(t, buffer.String(), "PUT")
    53  	assert.Contains(t, buffer.String(), "/example")
    54  
    55  	buffer.Reset()
    56  	PerformRequest(router, "DELETE", "/example")
    57  	assert.Contains(t, buffer.String(), "200")
    58  	assert.Contains(t, buffer.String(), "DELETE")
    59  	assert.Contains(t, buffer.String(), "/example")
    60  
    61  	buffer.Reset()
    62  	PerformRequest(router, "PATCH", "/example")
    63  	assert.Contains(t, buffer.String(), "200")
    64  	assert.Contains(t, buffer.String(), "PATCH")
    65  	assert.Contains(t, buffer.String(), "/example")
    66  
    67  	buffer.Reset()
    68  	PerformRequest(router, "HEAD", "/example")
    69  	assert.Contains(t, buffer.String(), "200")
    70  	assert.Contains(t, buffer.String(), "HEAD")
    71  	assert.Contains(t, buffer.String(), "/example")
    72  
    73  	buffer.Reset()
    74  	PerformRequest(router, "OPTIONS", "/example")
    75  	assert.Contains(t, buffer.String(), "200")
    76  	assert.Contains(t, buffer.String(), "OPTIONS")
    77  	assert.Contains(t, buffer.String(), "/example")
    78  
    79  	buffer.Reset()
    80  	PerformRequest(router, "GET", "/notfound")
    81  	assert.Contains(t, buffer.String(), "404")
    82  	assert.Contains(t, buffer.String(), "GET")
    83  	assert.Contains(t, buffer.String(), "/notfound")
    84  }
    85  
    86  func TestLoggerWithConfig(t *testing.T) {
    87  	buffer := new(strings.Builder)
    88  	router := New()
    89  	router.Use(LoggerWithConfig(LoggerConfig{Output: buffer}))
    90  	router.GET("/example", func(c *Context) {})
    91  	router.POST("/example", func(c *Context) {})
    92  	router.PUT("/example", func(c *Context) {})
    93  	router.DELETE("/example", func(c *Context) {})
    94  	router.PATCH("/example", func(c *Context) {})
    95  	router.HEAD("/example", func(c *Context) {})
    96  	router.OPTIONS("/example", func(c *Context) {})
    97  
    98  	PerformRequest(router, "GET", "/example?a=100")
    99  	assert.Contains(t, buffer.String(), "200")
   100  	assert.Contains(t, buffer.String(), "GET")
   101  	assert.Contains(t, buffer.String(), "/example")
   102  	assert.Contains(t, buffer.String(), "a=100")
   103  
   104  	// I wrote these first (extending the above) but then realized they are more
   105  	// like integration tests because they test the whole logging process rather
   106  	// than individual functions.  Im not sure where these should go.
   107  	buffer.Reset()
   108  	PerformRequest(router, "POST", "/example")
   109  	assert.Contains(t, buffer.String(), "200")
   110  	assert.Contains(t, buffer.String(), "POST")
   111  	assert.Contains(t, buffer.String(), "/example")
   112  
   113  	buffer.Reset()
   114  	PerformRequest(router, "PUT", "/example")
   115  	assert.Contains(t, buffer.String(), "200")
   116  	assert.Contains(t, buffer.String(), "PUT")
   117  	assert.Contains(t, buffer.String(), "/example")
   118  
   119  	buffer.Reset()
   120  	PerformRequest(router, "DELETE", "/example")
   121  	assert.Contains(t, buffer.String(), "200")
   122  	assert.Contains(t, buffer.String(), "DELETE")
   123  	assert.Contains(t, buffer.String(), "/example")
   124  
   125  	buffer.Reset()
   126  	PerformRequest(router, "PATCH", "/example")
   127  	assert.Contains(t, buffer.String(), "200")
   128  	assert.Contains(t, buffer.String(), "PATCH")
   129  	assert.Contains(t, buffer.String(), "/example")
   130  
   131  	buffer.Reset()
   132  	PerformRequest(router, "HEAD", "/example")
   133  	assert.Contains(t, buffer.String(), "200")
   134  	assert.Contains(t, buffer.String(), "HEAD")
   135  	assert.Contains(t, buffer.String(), "/example")
   136  
   137  	buffer.Reset()
   138  	PerformRequest(router, "OPTIONS", "/example")
   139  	assert.Contains(t, buffer.String(), "200")
   140  	assert.Contains(t, buffer.String(), "OPTIONS")
   141  	assert.Contains(t, buffer.String(), "/example")
   142  
   143  	buffer.Reset()
   144  	PerformRequest(router, "GET", "/notfound")
   145  	assert.Contains(t, buffer.String(), "404")
   146  	assert.Contains(t, buffer.String(), "GET")
   147  	assert.Contains(t, buffer.String(), "/notfound")
   148  }
   149  
   150  func TestLoggerWithFormatter(t *testing.T) {
   151  	buffer := new(strings.Builder)
   152  
   153  	d := DefaultWriter
   154  	DefaultWriter = buffer
   155  	defer func() {
   156  		DefaultWriter = d
   157  	}()
   158  
   159  	router := New()
   160  	router.Use(LoggerWithFormatter(func(param LogFormatterParams) string {
   161  		return fmt.Sprintf("[FORMATTER TEST] %v | %3d | %13v | %15s | %-7s %#v\n%s",
   162  			param.TimeStamp.Format("2006/01/02 - 15:04:05"),
   163  			param.StatusCode,
   164  			param.Latency,
   165  			param.ClientIP,
   166  			param.Method,
   167  			param.Path,
   168  			param.ErrorMessage,
   169  		)
   170  	}))
   171  	router.GET("/example", func(c *Context) {})
   172  	PerformRequest(router, "GET", "/example?a=100")
   173  
   174  	// output test
   175  	assert.Contains(t, buffer.String(), "[FORMATTER TEST]")
   176  	assert.Contains(t, buffer.String(), "200")
   177  	assert.Contains(t, buffer.String(), "GET")
   178  	assert.Contains(t, buffer.String(), "/example")
   179  	assert.Contains(t, buffer.String(), "a=100")
   180  }
   181  
   182  func TestLoggerWithConfigFormatting(t *testing.T) {
   183  	var gotParam LogFormatterParams
   184  	var gotKeys map[string]any
   185  	buffer := new(strings.Builder)
   186  
   187  	router := New()
   188  	router.engine.trustedCIDRs, _ = router.engine.prepareTrustedCIDRs()
   189  
   190  	router.Use(LoggerWithConfig(LoggerConfig{
   191  		Output: buffer,
   192  		Formatter: func(param LogFormatterParams) string {
   193  			// for assert test
   194  			gotParam = param
   195  
   196  			return fmt.Sprintf("[FORMATTER TEST] %v | %3d | %13v | %15s | %-7s %s\n%s",
   197  				param.TimeStamp.Format("2006/01/02 - 15:04:05"),
   198  				param.StatusCode,
   199  				param.Latency,
   200  				param.ClientIP,
   201  				param.Method,
   202  				param.Path,
   203  				param.ErrorMessage,
   204  			)
   205  		},
   206  	}))
   207  	router.GET("/example", func(c *Context) {
   208  		// set dummy ClientIP
   209  		c.Request.Header.Set("X-Forwarded-For", "20.20.20.20")
   210  		gotKeys = c.Keys
   211  		time.Sleep(time.Millisecond)
   212  	})
   213  	PerformRequest(router, "GET", "/example?a=100")
   214  
   215  	// output test
   216  	assert.Contains(t, buffer.String(), "[FORMATTER TEST]")
   217  	assert.Contains(t, buffer.String(), "200")
   218  	assert.Contains(t, buffer.String(), "GET")
   219  	assert.Contains(t, buffer.String(), "/example")
   220  	assert.Contains(t, buffer.String(), "a=100")
   221  
   222  	// LogFormatterParams test
   223  	assert.NotNil(t, gotParam.Request)
   224  	assert.NotEmpty(t, gotParam.TimeStamp)
   225  	assert.Equal(t, 200, gotParam.StatusCode)
   226  	assert.NotEmpty(t, gotParam.Latency)
   227  	assert.Equal(t, "20.20.20.20", gotParam.ClientIP)
   228  	assert.Equal(t, "GET", gotParam.Method)
   229  	assert.Equal(t, "/example?a=100", gotParam.Path)
   230  	assert.Empty(t, gotParam.ErrorMessage)
   231  	assert.Equal(t, gotKeys, gotParam.Keys)
   232  }
   233  
   234  func TestDefaultLogFormatter(t *testing.T) {
   235  	timeStamp := time.Unix(1544173902, 0).UTC()
   236  
   237  	termFalseParam := LogFormatterParams{
   238  		TimeStamp:    timeStamp,
   239  		StatusCode:   200,
   240  		Latency:      time.Second * 5,
   241  		ClientIP:     "20.20.20.20",
   242  		Method:       "GET",
   243  		Path:         "/",
   244  		ErrorMessage: "",
   245  		isTerm:       false,
   246  	}
   247  
   248  	termTrueParam := LogFormatterParams{
   249  		TimeStamp:    timeStamp,
   250  		StatusCode:   200,
   251  		Latency:      time.Second * 5,
   252  		ClientIP:     "20.20.20.20",
   253  		Method:       "GET",
   254  		Path:         "/",
   255  		ErrorMessage: "",
   256  		isTerm:       true,
   257  	}
   258  	termTrueLongDurationParam := LogFormatterParams{
   259  		TimeStamp:    timeStamp,
   260  		StatusCode:   200,
   261  		Latency:      time.Millisecond * 9876543210,
   262  		ClientIP:     "20.20.20.20",
   263  		Method:       "GET",
   264  		Path:         "/",
   265  		ErrorMessage: "",
   266  		isTerm:       true,
   267  	}
   268  
   269  	termFalseLongDurationParam := LogFormatterParams{
   270  		TimeStamp:    timeStamp,
   271  		StatusCode:   200,
   272  		Latency:      time.Millisecond * 9876543210,
   273  		ClientIP:     "20.20.20.20",
   274  		Method:       "GET",
   275  		Path:         "/",
   276  		ErrorMessage: "",
   277  		isTerm:       false,
   278  	}
   279  
   280  	assert.Equal(t, "[GIN] 2018/12/07 - 09:11:42 | 200 |            5s |     20.20.20.20 | GET      \"/\"\n", defaultLogFormatter(termFalseParam))
   281  	assert.Equal(t, "[GIN] 2018/12/07 - 09:11:42 | 200 |    2743h29m3s |     20.20.20.20 | GET      \"/\"\n", defaultLogFormatter(termFalseLongDurationParam))
   282  
   283  	assert.Equal(t, "[GIN] 2018/12/07 - 09:11:42 |\x1b[97;42m 200 \x1b[0m|            5s |     20.20.20.20 |\x1b[97;44m GET     \x1b[0m \"/\"\n", defaultLogFormatter(termTrueParam))
   284  	assert.Equal(t, "[GIN] 2018/12/07 - 09:11:42 |\x1b[97;42m 200 \x1b[0m|    2743h29m3s |     20.20.20.20 |\x1b[97;44m GET     \x1b[0m \"/\"\n", defaultLogFormatter(termTrueLongDurationParam))
   285  }
   286  
   287  func TestColorForMethod(t *testing.T) {
   288  	colorForMethod := func(method string) string {
   289  		p := LogFormatterParams{
   290  			Method: method,
   291  		}
   292  		return p.MethodColor()
   293  	}
   294  
   295  	assert.Equal(t, blue, colorForMethod("GET"), "get should be blue")
   296  	assert.Equal(t, cyan, colorForMethod("POST"), "post should be cyan")
   297  	assert.Equal(t, yellow, colorForMethod("PUT"), "put should be yellow")
   298  	assert.Equal(t, red, colorForMethod("DELETE"), "delete should be red")
   299  	assert.Equal(t, green, colorForMethod("PATCH"), "patch should be green")
   300  	assert.Equal(t, magenta, colorForMethod("HEAD"), "head should be magenta")
   301  	assert.Equal(t, white, colorForMethod("OPTIONS"), "options should be white")
   302  	assert.Equal(t, reset, colorForMethod("TRACE"), "trace is not defined and should be the reset color")
   303  }
   304  
   305  func TestColorForStatus(t *testing.T) {
   306  	colorForStatus := func(code int) string {
   307  		p := LogFormatterParams{
   308  			StatusCode: code,
   309  		}
   310  		return p.StatusCodeColor()
   311  	}
   312  
   313  	assert.Equal(t, green, colorForStatus(http.StatusOK), "2xx should be green")
   314  	assert.Equal(t, white, colorForStatus(http.StatusMovedPermanently), "3xx should be white")
   315  	assert.Equal(t, yellow, colorForStatus(http.StatusNotFound), "4xx should be yellow")
   316  	assert.Equal(t, red, colorForStatus(2), "other things should be red")
   317  }
   318  
   319  func TestResetColor(t *testing.T) {
   320  	p := LogFormatterParams{}
   321  	assert.Equal(t, string([]byte{27, 91, 48, 109}), p.ResetColor())
   322  }
   323  
   324  func TestIsOutputColor(t *testing.T) {
   325  	// test with isTerm flag true.
   326  	p := LogFormatterParams{
   327  		isTerm: true,
   328  	}
   329  
   330  	consoleColorMode = autoColor
   331  	assert.Equal(t, true, p.IsOutputColor())
   332  
   333  	ForceConsoleColor()
   334  	assert.Equal(t, true, p.IsOutputColor())
   335  
   336  	DisableConsoleColor()
   337  	assert.Equal(t, false, p.IsOutputColor())
   338  
   339  	// test with isTerm flag false.
   340  	p = LogFormatterParams{
   341  		isTerm: false,
   342  	}
   343  
   344  	consoleColorMode = autoColor
   345  	assert.Equal(t, false, p.IsOutputColor())
   346  
   347  	ForceConsoleColor()
   348  	assert.Equal(t, true, p.IsOutputColor())
   349  
   350  	DisableConsoleColor()
   351  	assert.Equal(t, false, p.IsOutputColor())
   352  
   353  	// reset console color mode.
   354  	consoleColorMode = autoColor
   355  }
   356  
   357  func TestErrorLogger(t *testing.T) {
   358  	router := New()
   359  	router.Use(ErrorLogger())
   360  	router.GET("/error", func(c *Context) {
   361  		c.Error(errors.New("this is an error")) //nolint: errcheck
   362  	})
   363  	router.GET("/abort", func(c *Context) {
   364  		c.AbortWithError(http.StatusUnauthorized, errors.New("no authorized")) //nolint: errcheck
   365  	})
   366  	router.GET("/print", func(c *Context) {
   367  		c.Error(errors.New("this is an error")) //nolint: errcheck
   368  		c.String(http.StatusInternalServerError, "hola!")
   369  	})
   370  
   371  	w := PerformRequest(router, "GET", "/error")
   372  	assert.Equal(t, http.StatusOK, w.Code)
   373  	assert.Equal(t, "{\"error\":\"this is an error\"}", w.Body.String())
   374  
   375  	w = PerformRequest(router, "GET", "/abort")
   376  	assert.Equal(t, http.StatusUnauthorized, w.Code)
   377  	assert.Equal(t, "{\"error\":\"no authorized\"}", w.Body.String())
   378  
   379  	w = PerformRequest(router, "GET", "/print")
   380  	assert.Equal(t, http.StatusInternalServerError, w.Code)
   381  	assert.Equal(t, "hola!{\"error\":\"this is an error\"}", w.Body.String())
   382  }
   383  
   384  func TestLoggerWithWriterSkippingPaths(t *testing.T) {
   385  	buffer := new(strings.Builder)
   386  	router := New()
   387  	router.Use(LoggerWithWriter(buffer, "/skipped"))
   388  	router.GET("/logged", func(c *Context) {})
   389  	router.GET("/skipped", func(c *Context) {})
   390  
   391  	PerformRequest(router, "GET", "/logged")
   392  	assert.Contains(t, buffer.String(), "200")
   393  
   394  	buffer.Reset()
   395  	PerformRequest(router, "GET", "/skipped")
   396  	assert.Contains(t, buffer.String(), "")
   397  }
   398  
   399  func TestLoggerWithConfigSkippingPaths(t *testing.T) {
   400  	buffer := new(strings.Builder)
   401  	router := New()
   402  	router.Use(LoggerWithConfig(LoggerConfig{
   403  		Output:    buffer,
   404  		SkipPaths: []string{"/skipped"},
   405  	}))
   406  	router.GET("/logged", func(c *Context) {})
   407  	router.GET("/skipped", func(c *Context) {})
   408  
   409  	PerformRequest(router, "GET", "/logged")
   410  	assert.Contains(t, buffer.String(), "200")
   411  
   412  	buffer.Reset()
   413  	PerformRequest(router, "GET", "/skipped")
   414  	assert.Contains(t, buffer.String(), "")
   415  }
   416  
   417  func TestDisableConsoleColor(t *testing.T) {
   418  	New()
   419  	assert.Equal(t, autoColor, consoleColorMode)
   420  	DisableConsoleColor()
   421  	assert.Equal(t, disableColor, consoleColorMode)
   422  
   423  	// reset console color mode.
   424  	consoleColorMode = autoColor
   425  }
   426  
   427  func TestForceConsoleColor(t *testing.T) {
   428  	New()
   429  	assert.Equal(t, autoColor, consoleColorMode)
   430  	ForceConsoleColor()
   431  	assert.Equal(t, forceColor, consoleColorMode)
   432  
   433  	// reset console color mode.
   434  	consoleColorMode = autoColor
   435  }
   436
View as plain text