sdk/go/httpserver/logger_test.go

   1 // Copyright (C) The Arvados Authors. All rights reserved.
   2 //
   3 // SPDX-License-Identifier: AGPL-3.0
   4
   5 package httpserver
   6
   7 import (
   8         "bytes"
   9         "context"
  10         "encoding/json"
  11         "net/http"
  12         "net/http/httptest"
  13         "testing"
  14         "time"
  15
  16         "git.curoverse.com/arvados.git/sdk/go/ctxlog"
  17         "github.com/sirupsen/logrus"
  18         check "gopkg.in/check.v1"
  19 )
  20
  21 func Test(t *testing.T) {
  22         check.TestingT(t)
  23 }
  24
  25 var _ = check.Suite(&Suite{})
  26
  27 type Suite struct{}
  28
  29 func (s *Suite) TestLogRequests(c *check.C) {
  30         captured := &bytes.Buffer{}
  31         log := logrus.New()
  32         log.Out = captured
  33         log.Formatter = &logrus.JSONFormatter{
  34                 TimestampFormat: time.RFC3339Nano,
  35         }
  36         ctx := ctxlog.Context(context.Background(), log)
  37
  38         h := AddRequestIDs(LogRequests(
  39                 http.HandlerFunc(func(w http.ResponseWriter, req *http.Request) {
  40                         w.Write([]byte("hello world"))
  41                 })))
  42
  43         req, err := http.NewRequest("GET", "https://foo.example/bar", nil)
  44         req.Header.Set("X-Forwarded-For", "1.2.3.4:12345")
  45         c.Assert(err, check.IsNil)
  46         resp := httptest.NewRecorder()
  47
  48         HandlerWithContext(ctx, h).ServeHTTP(resp, req)
  49
  50         dec := json.NewDecoder(captured)
  51
  52         gotReq := make(map[string]interface{})
  53         err = dec.Decode(&gotReq)
  54         c.Logf("%#v", gotReq)
  55         c.Check(gotReq["RequestID"], check.Matches, "req-[a-z0-9]{20}")
  56         c.Check(gotReq["reqForwardedFor"], check.Equals, "1.2.3.4:12345")
  57         c.Check(gotReq["msg"], check.Equals, "request")
  58
  59         gotResp := make(map[string]interface{})
  60         err = dec.Decode(&gotResp)
  61         c.Logf("%#v", gotResp)
  62         c.Check(gotResp["RequestID"], check.Equals, gotReq["RequestID"])
  63         c.Check(gotResp["reqForwardedFor"], check.Equals, "1.2.3.4:12345")
  64         c.Check(gotResp["msg"], check.Equals, "response")
  65
  66         c.Assert(gotResp["time"], check.FitsTypeOf, "")
  67         _, err = time.Parse(time.RFC3339Nano, gotResp["time"].(string))
  68         c.Check(err, check.IsNil)
  69
  70         for _, key := range []string{"timeToStatus", "timeWriteBody", "timeTotal"} {
  71                 c.Assert(gotResp[key], check.FitsTypeOf, float64(0))
  72                 c.Check(gotResp[key].(float64), check.Not(check.Equals), float64(0))
  73         }
  74 }