...

Source file src/github.com/gorilla/handlers/logging_test.go

Documentation: github.com/gorilla/handlers

     1  // Copyright 2013 The Gorilla Authors. All rights reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  package handlers
     6  
     7  import (
     8  	"bytes"
     9  	"encoding/base64"
    10  	"fmt"
    11  	"io/ioutil"
    12  	"math/rand"
    13  	"mime/multipart"
    14  	"net/http"
    15  	"net/http/httptest"
    16  	"net/url"
    17  	"os"
    18  	"path/filepath"
    19  	"strings"
    20  	"testing"
    21  	"time"
    22  )
    23  
    24  func TestMakeLogger(t *testing.T) {
    25  	rec := httptest.NewRecorder()
    26  	logger, w := makeLogger(rec)
    27  	// initial status
    28  	if logger.Status() != http.StatusOK {
    29  		t.Fatalf("wrong status, got %d want %d", logger.Status(), http.StatusOK)
    30  	}
    31  	// WriteHeader
    32  	w.WriteHeader(http.StatusInternalServerError)
    33  	if logger.Status() != http.StatusInternalServerError {
    34  		t.Fatalf("wrong status, got %d want %d", logger.Status(), http.StatusInternalServerError)
    35  	}
    36  	// Write
    37  	w.Write([]byte(ok))
    38  	if logger.Size() != len(ok) {
    39  		t.Fatalf("wrong size, got %d want %d", logger.Size(), len(ok))
    40  	}
    41  	// Header
    42  	w.Header().Set("key", "value")
    43  	if val := w.Header().Get("key"); val != "value" {
    44  		t.Fatalf("wrong header, got %s want %s", val, "value")
    45  	}
    46  }
    47  
    48  func TestLoggerCleanup(t *testing.T) {
    49  	rand.Seed(time.Now().UnixNano())
    50  
    51  	rbuf := make([]byte, 128)
    52  	if _, err := rand.Read(rbuf); err != nil {
    53  		t.Fatalf("Failed to generate random content: %v", err)
    54  	}
    55  	contents := base64.StdEncoding.EncodeToString(rbuf)
    56  
    57  	var body bytes.Buffer
    58  	body.WriteString(fmt.Sprintf(`
    59  --boundary
    60  Content-Disposition: form-data; name="buzz"; filename="example.txt"
    61  
    62  %s
    63  --boundary--
    64  `, contents))
    65  	r := multipart.NewReader(&body, "boundary")
    66  	form, err := r.ReadForm(0) // small max memory to force flush to disk
    67  	if err != nil {
    68  		t.Fatalf("Failed to read multipart form: %v", err)
    69  	}
    70  
    71  	tmpFiles, err := ioutil.ReadDir(os.TempDir())
    72  	if err != nil {
    73  		t.Fatalf("Failed to list %s: %v", os.TempDir(), err)
    74  	}
    75  
    76  	var tmpFile string
    77  	for _, f := range tmpFiles {
    78  		if !strings.HasPrefix(f.Name(), "multipart-") {
    79  			continue
    80  		}
    81  
    82  		path := filepath.Join(os.TempDir(), f.Name())
    83  		switch b, err := ioutil.ReadFile(path); {
    84  		case err != nil:
    85  			t.Fatalf("Failed to read %s: %v", path, err)
    86  		case string(b) != contents:
    87  			continue
    88  		default:
    89  			tmpFile = path
    90  			break
    91  		}
    92  	}
    93  
    94  	if tmpFile == "" {
    95  		t.Fatal("Could not find multipart form tmp file")
    96  	}
    97  
    98  	req := newRequest("GET", "/subdir/asdf")
    99  	req.MultipartForm = form
   100  
   101  	var buf bytes.Buffer
   102  	handler := http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
   103  		req.URL.Path = "/" // simulate http.StripPrefix and friends
   104  		w.WriteHeader(200)
   105  	})
   106  	logger := LoggingHandler(&buf, handler)
   107  	logger.ServeHTTP(httptest.NewRecorder(), req)
   108  
   109  	if _, err := os.Stat(tmpFile); err == nil || !os.IsNotExist(err) {
   110  		t.Fatalf("Expected %s to not exist, got %v", tmpFile, err)
   111  	}
   112  }
   113  
   114  func TestLogPathRewrites(t *testing.T) {
   115  	var buf bytes.Buffer
   116  
   117  	handler := http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
   118  		req.URL.Path = "/" // simulate http.StripPrefix and friends
   119  		w.WriteHeader(200)
   120  	})
   121  	logger := LoggingHandler(&buf, handler)
   122  
   123  	logger.ServeHTTP(httptest.NewRecorder(), newRequest("GET", "/subdir/asdf"))
   124  
   125  	if !strings.Contains(buf.String(), "GET /subdir/asdf HTTP") {
   126  		t.Fatalf("Got log %#v, wanted substring %#v", buf.String(), "GET /subdir/asdf HTTP")
   127  	}
   128  }
   129  
   130  func BenchmarkWriteLog(b *testing.B) {
   131  	loc, err := time.LoadLocation("Europe/Warsaw")
   132  	if err != nil {
   133  		b.Fatalf(err.Error())
   134  	}
   135  	ts := time.Date(1983, 05, 26, 3, 30, 45, 0, loc)
   136  
   137  	req := newRequest("GET", "http://example.com")
   138  	req.RemoteAddr = "192.168.100.5"
   139  
   140  	b.ResetTimer()
   141  
   142  	params := LogFormatterParams{
   143  		Request:    req,
   144  		URL:        *req.URL,
   145  		TimeStamp:  ts,
   146  		StatusCode: http.StatusUnauthorized,
   147  		Size:       500,
   148  	}
   149  
   150  	buf := &bytes.Buffer{}
   151  
   152  	for i := 0; i < b.N; i++ {
   153  		buf.Reset()
   154  		writeLog(buf, params)
   155  	}
   156  }
   157  
   158  func TestLogFormatterWriteLog_Scenario1(t *testing.T) {
   159  	formatter := writeLog
   160  	expected := "192.168.100.5 - - [26/May/1983:03:30:45 +0200] \"GET / HTTP/1.1\" 200 100\n"
   161  	LoggingScenario1(t, formatter, expected)
   162  }
   163  
   164  func TestLogFormatterCombinedLog_Scenario1(t *testing.T) {
   165  	formatter := writeCombinedLog
   166  	expected := "192.168.100.5 - - [26/May/1983:03:30:45 +0200] \"GET / HTTP/1.1\" 200 100 \"http://example.com\" " +
   167  		"\"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) " +
   168  		"AppleWebKit/537.33 (KHTML, like Gecko) Chrome/27.0.1430.0 Safari/537.33\"\n"
   169  	LoggingScenario1(t, formatter, expected)
   170  }
   171  
   172  func TestLogFormatterWriteLog_Scenario2(t *testing.T) {
   173  	formatter := writeLog
   174  	expected := "192.168.100.5 - - [26/May/1983:03:30:45 +0200] \"CONNECT www.example.com:443 HTTP/2.0\" 200 100\n"
   175  	LoggingScenario2(t, formatter, expected)
   176  }
   177  
   178  func TestLogFormatterCombinedLog_Scenario2(t *testing.T) {
   179  	formatter := writeCombinedLog
   180  	expected := "192.168.100.5 - - [26/May/1983:03:30:45 +0200] \"CONNECT www.example.com:443 HTTP/2.0\" 200 100 \"http://example.com\" " +
   181  		"\"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) " +
   182  		"AppleWebKit/537.33 (KHTML, like Gecko) Chrome/27.0.1430.0 Safari/537.33\"\n"
   183  	LoggingScenario2(t, formatter, expected)
   184  }
   185  
   186  func TestLogFormatterWriteLog_Scenario3(t *testing.T) {
   187  	formatter := writeLog
   188  	expected := "192.168.100.5 - kamil [26/May/1983:03:30:45 +0200] \"GET / HTTP/1.1\" 401 500\n"
   189  	LoggingScenario3(t, formatter, expected)
   190  }
   191  
   192  func TestLogFormatterCombinedLog_Scenario3(t *testing.T) {
   193  	formatter := writeCombinedLog
   194  	expected := "192.168.100.5 - kamil [26/May/1983:03:30:45 +0200] \"GET / HTTP/1.1\" 401 500 \"http://example.com\" " +
   195  		"\"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) " +
   196  		"AppleWebKit/537.33 (KHTML, like Gecko) Chrome/27.0.1430.0 Safari/537.33\"\n"
   197  	LoggingScenario3(t, formatter, expected)
   198  }
   199  
   200  func TestLogFormatterWriteLog_Scenario4(t *testing.T) {
   201  	formatter := writeLog
   202  	expected := "192.168.100.5 - - [26/May/1983:03:30:45 +0200] \"GET /test?abc=hello%20world&a=b%3F HTTP/1.1\" 200 100\n"
   203  	LoggingScenario4(t, formatter, expected)
   204  }
   205  
   206  func TestLogFormatterCombinedLog_Scenario5(t *testing.T) {
   207  	formatter := writeCombinedLog
   208  	expected := "::1 - kamil [26/May/1983:03:30:45 +0200] \"GET / HTTP/1.1\" 200 100 \"http://example.com\" " +
   209  		"\"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) " +
   210  		"AppleWebKit/537.33 (KHTML, like Gecko) Chrome/27.0.1430.0 Safari/537.33\"\n"
   211  	LoggingScenario5(t, formatter, expected)
   212  }
   213  
   214  func LoggingScenario1(t *testing.T, formatter LogFormatter, expected string) {
   215  	loc, err := time.LoadLocation("Europe/Warsaw")
   216  	if err != nil {
   217  		panic(err)
   218  	}
   219  	ts := time.Date(1983, 05, 26, 3, 30, 45, 0, loc)
   220  
   221  	// A typical request with an OK response
   222  	req := constructTypicalRequestOk()
   223  
   224  	buf := new(bytes.Buffer)
   225  	params := LogFormatterParams{
   226  		Request:    req,
   227  		URL:        *req.URL,
   228  		TimeStamp:  ts,
   229  		StatusCode: http.StatusOK,
   230  		Size:       100,
   231  	}
   232  
   233  	formatter(buf, params)
   234  	log := buf.String()
   235  
   236  	if log != expected {
   237  		t.Fatalf("wrong log, got %q want %q", log, expected)
   238  	}
   239  }
   240  
   241  func LoggingScenario2(t *testing.T, formatter LogFormatter, expected string) {
   242  	loc, err := time.LoadLocation("Europe/Warsaw")
   243  	if err != nil {
   244  		panic(err)
   245  	}
   246  	ts := time.Date(1983, 05, 26, 3, 30, 45, 0, loc)
   247  
   248  	// CONNECT request over http/2.0
   249  	req := constructConnectRequest()
   250  
   251  	buf := new(bytes.Buffer)
   252  	params := LogFormatterParams{
   253  		Request:    req,
   254  		URL:        *req.URL,
   255  		TimeStamp:  ts,
   256  		StatusCode: http.StatusOK,
   257  		Size:       100,
   258  	}
   259  	formatter(buf, params)
   260  	log := buf.String()
   261  
   262  	if log != expected {
   263  		t.Fatalf("wrong log, got %q want %q", log, expected)
   264  	}
   265  }
   266  
   267  func LoggingScenario3(t *testing.T, formatter LogFormatter, expected string) {
   268  	loc, err := time.LoadLocation("Europe/Warsaw")
   269  	if err != nil {
   270  		panic(err)
   271  	}
   272  	ts := time.Date(1983, 05, 26, 3, 30, 45, 0, loc)
   273  
   274  	// Request with an unauthorized user
   275  	req := constructTypicalRequestOk()
   276  	req.URL.User = url.User("kamil")
   277  
   278  	buf := new(bytes.Buffer)
   279  	params := LogFormatterParams{
   280  		Request:    req,
   281  		URL:        *req.URL,
   282  		TimeStamp:  ts,
   283  		StatusCode: http.StatusUnauthorized,
   284  		Size:       500,
   285  	}
   286  	formatter(buf, params)
   287  	log := buf.String()
   288  
   289  	if log != expected {
   290  		t.Fatalf("wrong log, got %q want %q", log, expected)
   291  	}
   292  }
   293  
   294  func LoggingScenario4(t *testing.T, formatter LogFormatter, expected string) {
   295  	loc, err := time.LoadLocation("Europe/Warsaw")
   296  	if err != nil {
   297  		panic(err)
   298  	}
   299  	ts := time.Date(1983, 05, 26, 3, 30, 45, 0, loc)
   300  
   301  	// Request with url encoded parameters
   302  	req := constructEncodedRequest()
   303  
   304  	buf := new(bytes.Buffer)
   305  	params := LogFormatterParams{
   306  		Request:    req,
   307  		URL:        *req.URL,
   308  		TimeStamp:  ts,
   309  		StatusCode: http.StatusOK,
   310  		Size:       100,
   311  	}
   312  	formatter(buf, params)
   313  	log := buf.String()
   314  
   315  	if log != expected {
   316  		t.Fatalf("wrong log, got %q want %q", log, expected)
   317  	}
   318  }
   319  
   320  func LoggingScenario5(t *testing.T, formatter LogFormatter, expected string) {
   321  	loc, err := time.LoadLocation("Europe/Warsaw")
   322  	if err != nil {
   323  		panic(err)
   324  	}
   325  	ts := time.Date(1983, 05, 26, 3, 30, 45, 0, loc)
   326  
   327  	req := constructTypicalRequestOk()
   328  	req.URL.User = url.User("kamil")
   329  	req.RemoteAddr = "::1"
   330  
   331  	buf := new(bytes.Buffer)
   332  	params := LogFormatterParams{
   333  		Request:    req,
   334  		URL:        *req.URL,
   335  		TimeStamp:  ts,
   336  		StatusCode: http.StatusOK,
   337  		Size:       100,
   338  	}
   339  	formatter(buf, params)
   340  	log := buf.String()
   341  
   342  	if log != expected {
   343  		t.Fatalf("wrong log, got %q want %q", log, expected)
   344  	}
   345  }
   346  
   347  // A typical request with an OK response
   348  func constructTypicalRequestOk() *http.Request {
   349  	req := newRequest("GET", "http://example.com")
   350  	req.RemoteAddr = "192.168.100.5"
   351  	req.Header.Set("Referer", "http://example.com")
   352  	req.Header.Set(
   353  		"User-Agent",
   354  		"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) AppleWebKit/537.33 "+
   355  			"(KHTML, like Gecko) Chrome/27.0.1430.0 Safari/537.33",
   356  	)
   357  	return req
   358  }
   359  
   360  // CONNECT request over http/2.0
   361  func constructConnectRequest() *http.Request {
   362  	req := &http.Request{
   363  		Method:     "CONNECT",
   364  		Host:       "www.example.com:443",
   365  		Proto:      "HTTP/2.0",
   366  		ProtoMajor: 2,
   367  		ProtoMinor: 0,
   368  		RemoteAddr: "192.168.100.5",
   369  		Header:     http.Header{},
   370  		URL:        &url.URL{Host: "www.example.com:443"},
   371  	}
   372  	req.Header.Set("Referer", "http://example.com")
   373  	req.Header.Set(
   374  		"User-Agent",
   375  		"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_8_2) AppleWebKit/537.33 "+
   376  			"(KHTML, like Gecko) Chrome/27.0.1430.0 Safari/537.33",
   377  	)
   378  	return req
   379  }
   380  
   381  func constructEncodedRequest() *http.Request {
   382  	req := constructTypicalRequestOk()
   383  	req.URL, _ = url.Parse("http://example.com/test?abc=hello%20world&a=b%3F")
   384  	return req
   385  }
   386  

View as plain text