transfer.sh/vendor/github.com/PuerkitoBio/ghost/handlers/log_test.go

package handlers

import (
	"bytes"
	"fmt"
	"log"
	"net/http"
	"net/http/httptest"
	"regexp"
	"testing"
	"time"
)

type testCase struct {
	tok string
	fmt string
	rx  *regexp.Regexp
}

func TestLog(t *testing.T) {
	log.SetFlags(0)
	now := time.Now()

	formats := []testCase{
		testCase{"remote-addr",
			"%s",
			regexp.MustCompile(`^127\.0\.0\.1:\d+\n$`),
		},
		testCase{"date",
			"%s",
			regexp.MustCompile(`^` + fmt.Sprintf("%04d-%02d-%02d", now.Year(), now.Month(), now.Day()) + `\n$`),
		},
		testCase{"method",
			"%s",
			regexp.MustCompile(`^GET\n$`),
		},
		testCase{"url",
			"%s",
			regexp.MustCompile(`^/\n$`),
		},
		testCase{"http-version",
			"%s",
			regexp.MustCompile(`^1\.1\n$`),
		},
		testCase{"status",
			"%d",
			regexp.MustCompile(`^200\n$`),
		},
		testCase{"referer",
			"%s",
			regexp.MustCompile(`^http://www\.test\.com\n$`),
		},
		testCase{"referrer",
			"%s",
			regexp.MustCompile(`^http://www\.test\.com\n$`),
		},
		testCase{"user-agent",
			"%s",
			regexp.MustCompile(`^Go \d+\.\d+ package http\n$`),
		},
		testCase{"bidon",
			"%s",
			regexp.MustCompile(`^\?\n$`),
		},
		testCase{"response-time",
			"%.3f",
			regexp.MustCompile(`^0\.1\d\d\n$`),
		},
		testCase{"req[Accept-Encoding]",
			"%s",
			regexp.MustCompile(`^gzip\n$`),
		},
		testCase{"res[blah]",
			"%s",
			regexp.MustCompile(`^$`),
		},
		testCase{"tiny",
			Ltiny,
			regexp.MustCompile(`^GET / 200  - 0\.1\d\d s\n$`),
		},
		testCase{"short",
			Lshort,
			regexp.MustCompile(`^127\.0\.0\.1:\d+ - GET / HTTP/1\.1 200  - 0\.1\d\d s\n$`),
		},
		testCase{"default",
			Ldefault,
			regexp.MustCompile(`^127\.0\.0\.1:\d+ - - \[\d{4}-\d{2}-\d{2}\] "GET / HTTP/1\.1" 200  "http://www\.test\.com" "Go \d+\.\d+ package http"\n$`),
		},
		testCase{"res[Content-Type]",
			"%s",
			regexp.MustCompile(`^text/plain\n$`),
		},
	}
	for _, tc := range formats {
		testLogCase(tc, t)
	}
}

func testLogCase(tc testCase, t *testing.T) {
	buf := bytes.NewBuffer(nil)
	log.SetOutput(buf)
	opts := NewLogOptions(log.Printf, tc.fmt, tc.tok)
	opts.DateFormat = "2006-01-02"
	h := LogHandler(http.HandlerFunc(
		func(w http.ResponseWriter, r *http.Request) {
			time.Sleep(100 * time.Millisecond)
			w.Header().Set("Content-Type", "text/plain")
			w.WriteHeader(200)
			w.Write([]byte("body"))
		}), opts)

	s := httptest.NewServer(h)
	defer s.Close()
	t.Logf("running %s...", tc.tok)
	req, err := http.NewRequest("GET", s.URL, nil)
	if err != nil {
		panic(err)
	}
	req.Header.Set("Referer", "http://www.test.com")
	req.Header.Set("Accept-Encoding", "gzip")
	res, err := http.DefaultClient.Do(req)
	if err != nil {
		panic(err)
	}
	assertStatus(http.StatusOK, res.StatusCode, t)
	ac := buf.String()
	assertTrue(tc.rx.MatchString(ac), fmt.Sprintf("expected log to match '%s', got '%s'", tc.rx.String(), ac), t)
}

func TestForwardedFor(t *testing.T) {
	rx := regexp.MustCompile(`^1\.1\.1\.1:0 - - \[\d{4}-\d{2}-\d{2}\] "GET / HTTP/1\.1" 200  "http://www\.test\.com" "Go \d+\.\d+ package http"\n$`)

	buf := bytes.NewBuffer(nil)
	log.SetOutput(buf)
	opts := NewLogOptions(log.Printf, Ldefault)
	opts.DateFormat = "2006-01-02"

	h := LogHandler(http.HandlerFunc(
		func(w http.ResponseWriter, r *http.Request) {
			time.Sleep(100 * time.Millisecond)
			w.Header().Set("Content-Type", "text/plain")
			w.WriteHeader(200)
			w.Write([]byte("body"))
		}), opts)

	s := httptest.NewServer(h)
	defer s.Close()
	t.Logf("running ForwardedFor...")
	req, err := http.NewRequest("GET", s.URL, nil)
	if err != nil {
		panic(err)
	}
	req.Header.Set("Referer", "http://www.test.com")
	req.Header.Set("X-Forwarded-For", "1.1.1.1")
	req.Header.Set("Accept-Encoding", "gzip")
	res, err := http.DefaultClient.Do(req)
	if err != nil {
		panic(err)
	}
	assertStatus(http.StatusOK, res.StatusCode, t)
	ac := buf.String()
	assertTrue(rx.MatchString(ac), fmt.Sprintf("expected log to match '%s', got '%s'", rx.String(), ac), t)
}

func TestImmediate(t *testing.T) {
	buf := bytes.NewBuffer(nil)
	log.SetFlags(0)
	log.SetOutput(buf)
	opts := NewLogOptions(nil, Ltiny)
	opts.Immediate = true
	h := LogHandler(http.HandlerFunc(
		func(w http.ResponseWriter, r *http.Request) {
			time.Sleep(100 * time.Millisecond)
			w.WriteHeader(200)
			w.Write([]byte("body"))
		}), opts)
	s := httptest.NewServer(h)
	defer s.Close()

	res, err := http.Get(s.URL)
	if err != nil {
		panic(err)
	}
	assertStatus(http.StatusOK, res.StatusCode, t)
	ac := buf.String()
	// Since it is Immediate logging, status is still 0 and response time is less than 100ms
	rx := regexp.MustCompile(`GET / 0  - 0\.0\d\d s\n`)
	assertTrue(rx.MatchString(ac), fmt.Sprintf("expected log to match '%s', got '%s'", rx.String(), ac), t)
}

func TestCustom(t *testing.T) {
	buf := bytes.NewBuffer(nil)
	log.SetFlags(0)
	log.SetOutput(buf)
	opts := NewLogOptions(nil, "%s %s", "method", "custom")
	opts.CustomTokens["custom"] = func(w http.ResponseWriter, r *http.Request) string {
		return "toto"
	}

	h := LogHandler(http.HandlerFunc(
		func(w http.ResponseWriter, r *http.Request) {
			time.Sleep(100 * time.Millisecond)
			w.WriteHeader(200)
			w.Write([]byte("body"))
		}), opts)
	s := httptest.NewServer(h)
	defer s.Close()

	res, err := http.Get(s.URL)
	if err != nil {
		panic(err)
	}
	assertStatus(http.StatusOK, res.StatusCode, t)
	ac := buf.String()
	rx := regexp.MustCompile(`GET toto`)
	assertTrue(rx.MatchString(ac), fmt.Sprintf("expected log to match '%s', got '%s'", rx.String(), ac), t)
}