fiber/middleware/logger/logger_test.go

//nolint:depguard // Because we test logging :D
package logger

import (
	"bufio"
	"bytes"
	"errors"
	"fmt"
	"io"
	"log"
	"net/http"
	"net/http/httptest"
	"os"
	"runtime"
	"strconv"
	"sync"
	"testing"
	"time"

	"github.com/gofiber/fiber/v3"
	fiberlog "github.com/gofiber/fiber/v3/log"
	"github.com/gofiber/fiber/v3/middleware/requestid"
	"github.com/stretchr/testify/require"
	"github.com/valyala/bytebufferpool"
	"github.com/valyala/fasthttp"
)

func benchmarkSetup(b *testing.B, app *fiber.App, uri string) {
	b.Helper()

	h := app.Handler()

	fctx := &fasthttp.RequestCtx{}
	fctx.Request.Header.SetMethod(fiber.MethodGet)
	fctx.Request.SetRequestURI(uri)

	b.ReportAllocs()
	b.ResetTimer()

	for n := 0; n < b.N; n++ {
		h(fctx)
	}
}

func benchmarkSetupParallel(b *testing.B, app *fiber.App, path string) {
	b.Helper()

	handler := app.Handler()

	b.ReportAllocs()
	b.ResetTimer()

	b.RunParallel(func(pb *testing.PB) {
		fctx := &fasthttp.RequestCtx{}
		fctx.Request.Header.SetMethod(fiber.MethodGet)
		fctx.Request.SetRequestURI(path)

		for pb.Next() {
			handler(fctx)
		}
	})
}

// go test -run Test_Logger
func Test_Logger(t *testing.T) {
	t.Parallel()
	app := fiber.New()

	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app.Use(New(Config{
		Format: "${error}",
		Stream: buf,
	}))

	app.Get("/", func(_ fiber.Ctx) error {
		return errors.New("some random error")
	})

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusInternalServerError, resp.StatusCode)
	require.Equal(t, "some random error", buf.String())
}

// go test -run Test_Logger_locals
func Test_Logger_locals(t *testing.T) {
	t.Parallel()
	app := fiber.New()

	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app.Use(New(Config{
		Format: "${locals:demo}",
		Stream: buf,
	}))

	app.Get("/", func(c fiber.Ctx) error {
		c.Locals("demo", "johndoe")
		return c.SendStatus(fiber.StatusOK)
	})

	app.Get("/int", func(c fiber.Ctx) error {
		c.Locals("demo", 55)
		return c.SendStatus(fiber.StatusOK)
	})

	app.Get("/empty", func(c fiber.Ctx) error {
		return c.SendStatus(fiber.StatusOK)
	})

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)
	require.Equal(t, "johndoe", buf.String())

	buf.Reset()

	resp, err = app.Test(httptest.NewRequest(fiber.MethodGet, "/int", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)
	require.Equal(t, "55", buf.String())

	buf.Reset()

	resp, err = app.Test(httptest.NewRequest(fiber.MethodGet, "/empty", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)
	require.Equal(t, "", buf.String())
}

// go test -run Test_Logger_Next
func Test_Logger_Next(t *testing.T) {
	t.Parallel()
	app := fiber.New()

	app.Use(New(Config{
		Next: func(_ fiber.Ctx) bool {
			return true
		},
	}))

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)
}

// go test -run Test_Logger_Done
func Test_Logger_Done(t *testing.T) {
	t.Parallel()
	buf := bytes.NewBuffer(nil)
	app := fiber.New()

	app.Use(New(Config{
		Done: func(c fiber.Ctx, logString []byte) {
			if c.Response().StatusCode() == fiber.StatusOK {
				_, err := buf.Write(logString)
				require.NoError(t, err)
			}
		},
	})).Get("/logging", func(ctx fiber.Ctx) error {
		return ctx.SendStatus(fiber.StatusOK)
	})

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/logging", nil))

	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)
	require.Positive(t, buf.Len(), 0)
}

// Test_Logger_Filter tests the Filter functionality of the logger middleware.
// It verifies that logs are written or skipped based on the filter condition.
func Test_Logger_Filter(t *testing.T) {
	t.Parallel()

	t.Run("Test Not Found", func(t *testing.T) {
		t.Parallel()
		app := fiber.New()

		logOutput := bytes.Buffer{}

		// Return true to skip logging for all requests != 404
		app.Use(New(Config{
			Skip: func(c fiber.Ctx) bool {
				return c.Response().StatusCode() != fiber.StatusNotFound
			},
			Stream: &logOutput,
		}))

		resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/nonexistent", nil))
		require.NoError(t, err)
		require.Equal(t, fiber.StatusNotFound, resp.StatusCode)

		// Expect logs for the 404 request
		require.Contains(t, logOutput.String(), "404")
	})

	t.Run("Test OK", func(t *testing.T) {
		t.Parallel()
		app := fiber.New()

		logOutput := bytes.Buffer{}

		// Return true to skip logging for all requests == 200
		app.Use(New(Config{
			Skip: func(c fiber.Ctx) bool {
				return c.Response().StatusCode() == fiber.StatusOK
			},
			Stream: &logOutput,
		}))

		app.Get("/", func(c fiber.Ctx) error {
			return c.SendStatus(fiber.StatusOK)
		})

		resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
		require.NoError(t, err)
		require.Equal(t, fiber.StatusOK, resp.StatusCode)

		// We skip logging for status == 200, so "200" should not appear
		require.NotContains(t, logOutput.String(), "200")
	})

	t.Run("Always Skip", func(t *testing.T) {
		t.Parallel()
		app := fiber.New()

		logOutput := bytes.Buffer{}

		// Filter always returns true => skip all logs
		app.Use(New(Config{
			Skip: func(_ fiber.Ctx) bool {
				return true // always skip
			},
			Stream: &logOutput,
		}))

		app.Get("/something", func(c fiber.Ctx) error {
			return c.Status(fiber.StatusTeapot).SendString("I'm a teapot")
		})

		_, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/something", nil))
		require.NoError(t, err)

		// Expect NO logs
		require.Empty(t, logOutput.String())
	})

	t.Run("Never Skip", func(t *testing.T) {
		t.Parallel()
		app := fiber.New()

		logOutput := bytes.Buffer{}

		// Filter always returns false => never skip logs
		app.Use(New(Config{
			Skip: func(_ fiber.Ctx) bool {
				return false // never skip
			},
			Stream: &logOutput,
		}))

		app.Get("/always", func(c fiber.Ctx) error {
			return c.Status(fiber.StatusTeapot).SendString("Teapot again")
		})

		_, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/always", nil))
		require.NoError(t, err)

		// Expect some logging - check any substring
		require.Contains(t, logOutput.String(), strconv.Itoa(fiber.StatusTeapot))
	})

	t.Run("Skip /healthz", func(t *testing.T) {
		t.Parallel()
		app := fiber.New()

		logOutput := bytes.Buffer{}

		// Filter returns true (skip logs) if the request path is /healthz
		app.Use(New(Config{
			Skip: func(c fiber.Ctx) bool {
				return c.Path() == "/healthz"
			},
			Stream: &logOutput,
		}))

		// Normal route
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello World!")
		})
		// Health route
		app.Get("/healthz", func(c fiber.Ctx) error {
			return c.SendString("OK")
		})

		// Request to "/" -> should be logged
		_, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
		require.NoError(t, err)
		require.Contains(t, logOutput.String(), "200")

		// Reset output buffer
		logOutput.Reset()

		// Request to "/healthz" -> should be skipped
		_, err = app.Test(httptest.NewRequest(fiber.MethodGet, "/healthz", nil))
		require.NoError(t, err)
		require.Empty(t, logOutput.String())
	})
}

// go test -run Test_Logger_ErrorTimeZone
func Test_Logger_ErrorTimeZone(t *testing.T) {
	t.Parallel()
	app := fiber.New()

	app.Use(New(Config{
		TimeZone: "invalid",
	}))

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)
}

// go test -run Test_Logger_Fiber_Logger
func Test_Logger_LoggerToWriter(t *testing.T) {
	app := fiber.New()

	buf := bytebufferpool.Get()
	t.Cleanup(func() {
		bytebufferpool.Put(buf)
	})

	logger := fiberlog.DefaultLogger()
	stdlogger, ok := logger.Logger().(*log.Logger)
	require.True(t, ok)

	stdlogger.SetFlags(0)
	logger.SetOutput(buf)

	testCases := []struct {
		levelStr string
		level    fiberlog.Level
	}{
		{
			level:    fiberlog.LevelTrace,
			levelStr: "Trace",
		},
		{
			level:    fiberlog.LevelDebug,
			levelStr: "Debug",
		},
		{
			level:    fiberlog.LevelInfo,
			levelStr: "Info",
		},
		{
			level:    fiberlog.LevelWarn,
			levelStr: "Warn",
		},
		{
			level:    fiberlog.LevelError,
			levelStr: "Error",
		},
	}

	for _, tc := range testCases {
		level := strconv.Itoa(int(tc.level))
		t.Run(level, func(t *testing.T) {
			buf.Reset()

			app.Use("/"+level, New(Config{
				Format: "${error}",
				Stream: LoggerToWriter(logger, tc.
					level),
			}))

			app.Get("/"+level, func(_ fiber.Ctx) error {
				return errors.New("some random error")
			})

			resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/"+level, nil))
			require.NoError(t, err)
			require.Equal(t, fiber.StatusInternalServerError, resp.StatusCode)
			require.Equal(t, "["+tc.levelStr+"] some random error\n", buf.String())
		})

		require.Panics(t, func() {
			LoggerToWriter(logger, fiberlog.LevelPanic)
		})

		require.Panics(t, func() {
			LoggerToWriter(logger, fiberlog.LevelFatal)
		})

		require.Panics(t, func() {
			LoggerToWriter(nil, fiberlog.LevelFatal)
		})
	}
}

type fakeErrorOutput int

func (o *fakeErrorOutput) Write([]byte) (int, error) {
	*o++
	return 0, errors.New("fake output")
}

// go test -run Test_Logger_ErrorOutput_WithoutColor
func Test_Logger_ErrorOutput_WithoutColor(t *testing.T) {
	t.Parallel()
	o := new(fakeErrorOutput)
	app := fiber.New()

	app.Use(New(Config{
		Stream:        o,
		DisableColors: true,
	}))

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)
	require.EqualValues(t, 2, *o)
}

// go test -run Test_Logger_ErrorOutput
func Test_Logger_ErrorOutput(t *testing.T) {
	t.Parallel()
	o := new(fakeErrorOutput)
	app := fiber.New()

	app.Use(New(Config{
		Stream: o,
	}))

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)
	require.EqualValues(t, 2, *o)
}

// go test -run Test_Logger_All
func Test_Logger_All(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(New(Config{
		Format: "${pid}${reqHeaders}${referer}${scheme}${protocol}${ip}${ips}${host}${url}${ua}${body}${route}${black}${red}${green}${yellow}${blue}${magenta}${cyan}${white}${reset}${error}${reqHeader:test}${query:test}${form:test}${cookie:test}${non}",
		Stream: buf,
	}))

	// Alias colors
	colors := app.Config().ColorScheme

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/?foo=bar", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)

	expected := fmt.Sprintf("%dHost=example.comhttpHTTP/1.10.0.0.0example.com/?foo=bar/%s%s%s%s%s%s%s%s%sCannot GET /", os.Getpid(), colors.Black, colors.Red, colors.Green, colors.Yellow, colors.Blue, colors.Magenta, colors.Cyan, colors.White, colors.Reset)
	require.Equal(t, expected, buf.String())
}

func Test_Logger_CLF_Format(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(New(Config{
		Format: CommonFormat,
		Stream: buf,
	}))

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/?foo=bar", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)

	expected := fmt.Sprintf("0.0.0.0 - - [%s] \"%s %s %s\" %d %d\n",
		time.Now().Format("15:04:05"),
		fiber.MethodGet, "/?foo=bar", "HTTP/1.1",
		fiber.StatusNotFound,
		0)
	logResponse := buf.String()
	require.Equal(t, expected, logResponse)
}

func Test_Logger_Combined_CLF_Format(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(New(Config{
		Format: CombinedFormat,
		Stream: buf,
	}))
	const expectedUA = "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/74.0.3729.169 Safari/537.36"
	const expectedReferer = "http://example.com"
	req := httptest.NewRequest(fiber.MethodGet, "/?foo=bar", nil)
	req.Header.Set("Referer", expectedReferer)
	req.Header.Set("User-Agent", expectedUA)
	resp, err := app.Test(req)
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)

	expected := fmt.Sprintf("0.0.0.0 - - [%s] %q %d %d %q %q\n",
		time.Now().Format("15:04:05"),
		fmt.Sprintf("%s %s %s", fiber.MethodGet, "/?foo=bar", "HTTP/1.1"),
		fiber.StatusNotFound,
		0,
		expectedReferer,
		expectedUA)
	logResponse := buf.String()
	require.Equal(t, expected, logResponse)
}

func Test_Logger_Json_Format(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(New(Config{
		Format: JSONFormat,
		Stream: buf,
	}))

	req := httptest.NewRequest(fiber.MethodGet, "/?foo=bar", nil)
	resp, err := app.Test(req)
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)

	expected := fmt.Sprintf(
		"{\"time\":%q,\"ip\":%q,\"method\":%q,\"url\":%q,\"status\":%d,\"bytesSent\":%d}\n",
		time.Now().Format("15:04:05"),
		"0.0.0.0",
		fiber.MethodGet,
		"/?foo=bar",
		fiber.StatusNotFound,
		0,
	)
	logResponse := buf.String()
	require.Equal(t, expected, logResponse)
}

func Test_Logger_ECS_Format(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(New(Config{
		Format: ECSFormat,
		Stream: buf,
	}))

	req := httptest.NewRequest(fiber.MethodGet, "/?foo=bar", nil)
	resp, err := app.Test(req)
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)

	expected := fmt.Sprintf(
		"{\"@timestamp\":%q,\"ecs\":{\"version\":\"1.6.0\"},\"client\":{\"ip\":%q},\"http\":{\"request\":{\"method\":%q,\"url\":%q,\"protocol\":%q},\"response\":{\"status_code\":%d,\"body\":{\"bytes\":%d}}},\"log\":{\"level\":\"INFO\",\"logger\":\"fiber\"},\"message\":%q}\n",
		time.Now().Format("15:04:05"),
		"0.0.0.0",
		fiber.MethodGet,
		"/?foo=bar",
		"HTTP/1.1",
		fiber.StatusNotFound,
		0,
		fmt.Sprintf("%s %s responded with %d", fiber.MethodGet, "/?foo=bar", fiber.StatusNotFound),
	)
	logResponse := buf.String()
	require.Equal(t, expected, logResponse)
}

func getLatencyTimeUnits() []struct {
	unit string
	div  time.Duration
} {
	// windows does not support µs sleep precision
	// https://github.com/golang/go/issues/29485
	if runtime.GOOS == "windows" {
		return []struct {
			unit string
			div  time.Duration
		}{
			{unit: "ms", div: time.Millisecond},
			{unit: "s", div: time.Second},
		}
	}
	return []struct {
		unit string
		div  time.Duration
	}{
		{unit: "µs", div: time.Microsecond},
		{unit: "ms", div: time.Millisecond},
		{unit: "s", div: time.Second},
	}
}

// go test -run Test_Logger_WithLatency
func Test_Logger_WithLatency(t *testing.T) {
	buff := bytebufferpool.Get()
	defer bytebufferpool.Put(buff)
	app := fiber.New()

	logger := New(Config{
		Stream: buff,
		Format: "${latency}",
	})
	app.Use(logger)

	// Define a list of time units to test
	timeUnits := getLatencyTimeUnits()

	// Initialize a new time unit
	sleepDuration := 1 * time.Nanosecond

	// Define a test route that sleeps
	app.Get("/test", func(c fiber.Ctx) error {
		time.Sleep(sleepDuration)
		return c.SendStatus(fiber.StatusOK)
	})

	// Loop through each time unit and assert that the log output contains the expected latency value
	for _, tu := range timeUnits {
		// Update the sleep duration for the next iteration
		sleepDuration = 1 * tu.div

		// Create a new HTTP request to the test route
		resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/test", nil), fiber.TestConfig{
			Timeout:       3 * time.Second,
			FailOnTimeout: true,
		})
		require.NoError(t, err)
		require.Equal(t, fiber.StatusOK, resp.StatusCode)

		// Assert that the log output contains the expected latency value in the current time unit
		require.True(t, bytes.HasSuffix(buff.Bytes(), []byte(tu.unit)), "Expected latency to be in %s, got %s", tu.unit, buff.String())

		// Reset the buffer
		buff.Reset()
	}
}

// go test -run Test_Logger_WithLatency_DefaultFormat
func Test_Logger_WithLatency_DefaultFormat(t *testing.T) {
	buff := bytebufferpool.Get()
	defer bytebufferpool.Put(buff)
	app := fiber.New()

	logger := New(Config{
		Stream: buff,
	})
	app.Use(logger)

	// Define a list of time units to test
	timeUnits := getLatencyTimeUnits()

	// Initialize a new time unit
	sleepDuration := 1 * time.Nanosecond

	// Define a test route that sleeps
	app.Get("/test", func(c fiber.Ctx) error {
		time.Sleep(sleepDuration)
		return c.SendStatus(fiber.StatusOK)
	})

	// Loop through each time unit and assert that the log output contains the expected latency value
	for _, tu := range timeUnits {
		// Update the sleep duration for the next iteration
		sleepDuration = 1 * tu.div

		// Create a new HTTP request to the test route
		resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/test", nil), fiber.TestConfig{
			Timeout:       2 * time.Second,
			FailOnTimeout: true,
		})
		require.NoError(t, err)
		require.Equal(t, fiber.StatusOK, resp.StatusCode)

		// Assert that the log output contains the expected latency value in the current time unit
		// parse out the latency value from the log output
		latency := bytes.Split(buff.Bytes(), []byte(" | "))[2]
		// Assert that the latency value is in the current time unit
		require.True(t, bytes.HasSuffix(latency, []byte(tu.unit)), "Expected latency to be in %s, got %s", tu.unit, latency)

		// Reset the buffer
		buff.Reset()
	}
}

// go test -run Test_Query_Params
func Test_Query_Params(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(New(Config{
		Format: "${queryParams}",
		Stream: buf,
	}))

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/?foo=bar&baz=moz", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)

	expected := "foo=bar&baz=moz"
	require.Equal(t, expected, buf.String())
}

// go test -run Test_Response_Body
func Test_Response_Body(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(New(Config{
		Format: "${resBody}",
		Stream: buf,
	}))

	app.Get("/", func(c fiber.Ctx) error {
		return c.SendString("Sample response body")
	})

	app.Post("/test", func(c fiber.Ctx) error {
		return c.Send([]byte("Post in test"))
	})

	_, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	require.NoError(t, err)

	expectedGetResponse := "Sample response body"
	require.Equal(t, expectedGetResponse, buf.String())

	buf.Reset() // Reset buffer to test POST
	_, err = app.Test(httptest.NewRequest(fiber.MethodPost, "/test", nil))

	expectedPostResponse := "Post in test"
	require.NoError(t, err)
	require.Equal(t, expectedPostResponse, buf.String())
}

// go test -run Test_Request_Body
func Test_Request_Body(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)
	app := fiber.New()

	app.Use(New(Config{
		Format: "${bytesReceived} ${bytesSent} ${status}",
		Stream: buf,
	}))

	app.Post("/", func(c fiber.Ctx) error {
		c.Response().Header.SetContentLength(5)
		return c.SendString("World")
	})

	// Create a POST request with a body
	body := []byte("Hello")
	req := httptest.NewRequest(fiber.MethodPost, "/", bytes.NewReader(body))
	req.Header.Set("Content-Type", "application/octet-stream")

	_, err := app.Test(req)
	require.NoError(t, err)
	require.Equal(t, "5 5 200", buf.String())
}

// go test -run Test_Logger_AppendUint
func Test_Logger_AppendUint(t *testing.T) {
	t.Parallel()
	app := fiber.New()

	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app.Use(New(Config{
		Format: "${bytesReceived} ${bytesSent} ${status}",
		Stream: buf,
	}))

	app.Get("/", func(c fiber.Ctx) error {
		return c.SendString("hello")
	})

	app.Get("/content", func(c fiber.Ctx) error {
		c.Response().Header.SetContentLength(5)
		return c.SendString("hello")
	})

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)
	require.Equal(t, "-2 0 200", buf.String())

	buf.Reset()
	resp, err = app.Test(httptest.NewRequest(fiber.MethodGet, "/content", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)
	require.Equal(t, "-2 5 200", buf.String())
}

// go test -run Test_Logger_Data_Race -race
func Test_Logger_Data_Race(t *testing.T) {
	t.Parallel()
	app := fiber.New()

	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app.Use(New(ConfigDefault))
	app.Use(New(Config{
		Format: "${time} | ${pid} | ${locals:requestid} | ${status} | ${latency} | ${method} | ${path}\n",
	}))

	app.Get("/", func(c fiber.Ctx) error {
		return c.SendString("hello")
	})

	var (
		resp1, resp2 *http.Response
		err1, err2   error
	)
	wg := &sync.WaitGroup{}
	wg.Add(1)
	go func() {
		resp1, err1 = app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
		wg.Done()
	}()
	resp2, err2 = app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	wg.Wait()

	require.NoError(t, err1)
	require.Equal(t, fiber.StatusOK, resp1.StatusCode)
	require.NoError(t, err2)
	require.Equal(t, fiber.StatusOK, resp2.StatusCode)
}

// go test -run Test_Response_Header
func Test_Response_Header(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(requestid.New(requestid.Config{
		Next:      nil,
		Header:    fiber.HeaderXRequestID,
		Generator: func() string { return "Hello fiber!" },
	}))
	app.Use(New(Config{
		Format: "${respHeader:X-Request-ID}",
		Stream: buf,
	}))
	app.Get("/", func(c fiber.Ctx) error {
		return c.SendString("Hello fiber!")
	})

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))

	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)
	require.Equal(t, "Hello fiber!", buf.String())
}

// go test -run Test_Req_Header
func Test_Req_Header(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(New(Config{
		Format: "${reqHeader:test}",
		Stream: buf,
	}))
	app.Get("/", func(c fiber.Ctx) error {
		return c.SendString("Hello fiber!")
	})
	headerReq := httptest.NewRequest(fiber.MethodGet, "/", nil)
	headerReq.Header.Add("test", "Hello fiber!")

	resp, err := app.Test(headerReq)
	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)
	require.Equal(t, "Hello fiber!", buf.String())
}

// go test -run Test_ReqHeader_Header
func Test_ReqHeader_Header(t *testing.T) {
	t.Parallel()
	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(New(Config{
		Format: "${reqHeader:test}",
		Stream: buf,
	}))
	app.Get("/", func(c fiber.Ctx) error {
		return c.SendString("Hello fiber!")
	})
	reqHeaderReq := httptest.NewRequest(fiber.MethodGet, "/", nil)
	reqHeaderReq.Header.Add("test", "Hello fiber!")

	resp, err := app.Test(reqHeaderReq)
	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)
	require.Equal(t, "Hello fiber!", buf.String())
}

// go test -run Test_CustomTags
func Test_CustomTags(t *testing.T) {
	t.Parallel()
	customTag := "it is a custom tag"

	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app := fiber.New()

	app.Use(New(Config{
		Format: "${custom_tag}",
		CustomTags: map[string]LogFunc{
			"custom_tag": func(output Buffer, _ fiber.Ctx, _ *Data, _ string) (int, error) {
				return output.WriteString(customTag)
			},
		},
		Stream: buf,
	}))
	app.Get("/", func(c fiber.Ctx) error {
		return c.SendString("Hello fiber!")
	})
	reqHeaderReq := httptest.NewRequest(fiber.MethodGet, "/", nil)
	reqHeaderReq.Header.Add("test", "Hello fiber!")

	resp, err := app.Test(reqHeaderReq)
	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)
	require.Equal(t, customTag, buf.String())
}

// go test -run Test_Logger_ByteSent_Streaming
func Test_Logger_ByteSent_Streaming(t *testing.T) {
	t.Parallel()
	app := fiber.New()

	buf := bytebufferpool.Get()
	defer bytebufferpool.Put(buf)

	app.Use(New(Config{
		Format: "${bytesReceived} ${bytesSent} ${status}",
		Stream: buf,
	}))

	app.Get("/", func(c fiber.Ctx) error {
		c.Set("Connection", "keep-alive")
		c.Set("Transfer-Encoding", "chunked")
		c.RequestCtx().SetBodyStreamWriter(func(w *bufio.Writer) {
			var i int
			for {
				i++
				msg := fmt.Sprintf("%d - the time is %v", i, time.Now())
				fmt.Fprintf(w, "data: Message: %s\n\n", msg)
				err := w.Flush()
				if err != nil {
					break
				}
				if i == 10 {
					break
				}
			}
		})
		return nil
	})

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusOK, resp.StatusCode)

	// -2 means identity, -1 means chunked, 200 status
	require.Equal(t, "-2 -1 200", buf.String())
}

type fakeOutput int

func (o *fakeOutput) Write(b []byte) (int, error) {
	*o++
	return len(b), nil
}

// go test -run Test_Logger_EnableColors
func Test_Logger_EnableColors(t *testing.T) {
	t.Parallel()
	o := new(fakeOutput)
	app := fiber.New()

	app.Use(New(Config{
		Stream: o,
	}))

	resp, err := app.Test(httptest.NewRequest(fiber.MethodGet, "/", nil))
	require.NoError(t, err)
	require.Equal(t, fiber.StatusNotFound, resp.StatusCode)
	require.EqualValues(t, 1, *o)
}

// go test -v -run=^$ -bench=Benchmark_Logger$ -benchmem -count=4
func Benchmark_Logger(b *testing.B) {
	b.Run("NoMiddleware", func(bb *testing.B) {
		app := fiber.New()
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello, World!")
		})
		benchmarkSetup(bb, app, "/")
	})

	b.Run("WithBytesAndStatus", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${bytesReceived} ${bytesSent} ${status}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			c.Set("test", "test")
			return c.SendString("Hello, World!")
		})
		benchmarkSetup(bb, app, "/")
	})

	b.Run("DefaultFormat", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello, World!")
		})
		benchmarkSetup(bb, app, "/")
	})

	b.Run("DefaultFormatDisableColors", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Stream:        io.Discard,
			DisableColors: true,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello, World!")
		})
		benchmarkSetup(bb, app, "/")
	})

	b.Run("DefaultFormatWithFiberLog", func(bb *testing.B) {
		app := fiber.New()
		logger := fiberlog.DefaultLogger()
		logger.SetOutput(io.Discard)
		app.Use(New(Config{
			Stream: LoggerToWriter(logger, fiberlog.LevelDebug),
		}))
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello, World!")
		})
		benchmarkSetup(bb, app, "/")
	})

	b.Run("WithTagParameter", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${bytesReceived} ${bytesSent} ${status} ${reqHeader:test}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			c.Set("test", "test")
			return c.SendString("Hello, World!")
		})
		benchmarkSetup(bb, app, "/")
	})

	b.Run("WithLocals", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${locals:demo}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			c.Locals("demo", "johndoe")
			return c.SendStatus(fiber.StatusOK)
		})
		benchmarkSetup(bb, app, "/")
	})

	b.Run("WithLocalsInt", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${locals:demo}",
			Stream: io.Discard,
		}))
		app.Get("/int", func(c fiber.Ctx) error {
			c.Locals("demo", 55)
			return c.SendStatus(fiber.StatusOK)
		})
		benchmarkSetup(bb, app, "/int")
	})

	b.Run("WithCustomDone", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Done: func(c fiber.Ctx, logString []byte) {
				if c.Response().StatusCode() == fiber.StatusOK {
					io.Discard.Write(logString) //nolint:errcheck // ignore error
				}
			},
			Stream: io.Discard,
		}))
		app.Get("/logging", func(ctx fiber.Ctx) error {
			return ctx.SendStatus(fiber.StatusOK)
		})
		benchmarkSetup(bb, app, "/logging")
	})

	b.Run("WithAllTags", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${pid}${reqHeaders}${referer}${scheme}${protocol}${ip}${ips}${host}${url}${ua}${body}${route}${black}${red}${green}${yellow}${blue}${magenta}${cyan}${white}${reset}${error}${reqHeader:test}${query:test}${form:test}${cookie:test}${non}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello, World!")
		})
		benchmarkSetup(bb, app, "/")
	})

	b.Run("Streaming", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${bytesReceived} ${bytesSent} ${status}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			c.Set("Connection", "keep-alive")
			c.Set("Transfer-Encoding", "chunked")
			c.RequestCtx().SetBodyStreamWriter(func(w *bufio.Writer) {
				var i int
				for {
					i++
					msg := fmt.Sprintf("%d - the time is %v", i, time.Now())
					fmt.Fprintf(w, "data: Message: %s\n\n", msg)
					err := w.Flush()
					if err != nil {
						break
					}
					if i == 10 {
						break
					}
				}
			})
			return nil
		})
		benchmarkSetup(bb, app, "/")
	})

	b.Run("WithBody", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${resBody}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Sample response body")
		})
		benchmarkSetup(bb, app, "/")
	})
}

// go test -v -run=^$ -bench=Benchmark_Logger_Parallel$ -benchmem -count=4
func Benchmark_Logger_Parallel(b *testing.B) {
	b.Run("NoMiddleware", func(bb *testing.B) {
		app := fiber.New()
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello, World!")
		})
		benchmarkSetupParallel(bb, app, "/")
	})

	b.Run("WithBytesAndStatus", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${bytesReceived} ${bytesSent} ${status}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			c.Set("test", "test")
			return c.SendString("Hello, World!")
		})
		benchmarkSetupParallel(bb, app, "/")
	})

	b.Run("DefaultFormat", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello, World!")
		})
		benchmarkSetupParallel(bb, app, "/")
	})

	b.Run("DefaultFormatWithFiberLog", func(bb *testing.B) {
		app := fiber.New()
		logger := fiberlog.DefaultLogger()
		logger.SetOutput(io.Discard)
		app.Use(New(Config{
			Stream: LoggerToWriter(logger, fiberlog.LevelDebug),
		}))
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello, World!")
		})
		benchmarkSetupParallel(bb, app, "/")
	})

	b.Run("DefaultFormatDisableColors", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Stream:        io.Discard,
			DisableColors: true,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello, World!")
		})
		benchmarkSetupParallel(bb, app, "/")
	})

	b.Run("WithTagParameter", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${bytesReceived} ${bytesSent} ${status} ${reqHeader:test}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			c.Set("test", "test")
			return c.SendString("Hello, World!")
		})
		benchmarkSetupParallel(bb, app, "/")
	})

	b.Run("WithLocals", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${locals:demo}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			c.Locals("demo", "johndoe")
			return c.SendStatus(fiber.StatusOK)
		})
		benchmarkSetupParallel(bb, app, "/")
	})

	b.Run("WithLocalsInt", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${locals:demo}",
			Stream: io.Discard,
		}))
		app.Get("/int", func(c fiber.Ctx) error {
			c.Locals("demo", 55)
			return c.SendStatus(fiber.StatusOK)
		})
		benchmarkSetupParallel(bb, app, "/int")
	})

	b.Run("WithCustomDone", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Done: func(c fiber.Ctx, logString []byte) {
				if c.Response().StatusCode() == fiber.StatusOK {
					io.Discard.Write(logString) //nolint:errcheck // ignore error
				}
			},
			Stream: io.Discard,
		}))
		app.Get("/logging", func(ctx fiber.Ctx) error {
			return ctx.SendStatus(fiber.StatusOK)
		})
		benchmarkSetupParallel(bb, app, "/logging")
	})

	b.Run("WithAllTags", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${pid}${reqHeaders}${referer}${scheme}${protocol}${ip}${ips}${host}${url}${ua}${body}${route}${black}${red}${green}${yellow}${blue}${magenta}${cyan}${white}${reset}${error}${reqHeader:test}${query:test}${form:test}${cookie:test}${non}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Hello, World!")
		})
		benchmarkSetupParallel(bb, app, "/")
	})

	b.Run("Streaming", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${bytesReceived} ${bytesSent} ${status}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			c.Set("Connection", "keep-alive")
			c.Set("Transfer-Encoding", "chunked")
			c.RequestCtx().SetBodyStreamWriter(func(w *bufio.Writer) {
				var i int
				for {
					i++
					msg := fmt.Sprintf("%d - the time is %v", i, time.Now())
					fmt.Fprintf(w, "data: Message: %s\n\n", msg)
					err := w.Flush()
					if err != nil {
						break
					}
					if i == 10 {
						break
					}
				}
			})
			return nil
		})
		benchmarkSetupParallel(bb, app, "/")
	})

	b.Run("WithBody", func(bb *testing.B) {
		app := fiber.New()
		app.Use(New(Config{
			Format: "${resBody}",
			Stream: io.Discard,
		}))
		app.Get("/", func(c fiber.Ctx) error {
			return c.SendString("Sample response body")
		})
		benchmarkSetupParallel(bb, app, "/")
	})
}