middleware.go

Documentation: github.com/ory/x/reqlog

     1  package reqlog
     2  
     3  import (
     4  	"net/http"
     5  	"sync"
     6  	"time"
     7  
     8  	"github.com/sirupsen/logrus"
     9  	"github.com/urfave/negroni"
    10  
    11  	"github.com/ory/x/logrusx"
    12  )
    13  
    14  type timer interface {
    15  	Now() time.Time
    16  	Since(time.Time) time.Duration
    17  }
    18  
    19  type realClock struct{}
    20  
    21  func (rc *realClock) Now() time.Time {
    22  	return time.Now()
    23  }
    24  
    25  func (rc *realClock) Since(t time.Time) time.Duration {
    26  	return time.Since(t)
    27  }
    28  
    29  // Middleware is a middleware handler that logs the request as it goes in and the response as it goes out.
    30  type Middleware struct {
    31  	// Logger is the log.Logger instance used to log messages with the Logger middleware
    32  	Logger *logrusx.Logger
    33  	// Name is the name of the application as recorded in latency metrics
    34  	Name   string
    35  	Before func(*logrusx.Logger, *http.Request, string) *logrusx.Logger
    36  	After  func(*logrusx.Logger, *http.Request, negroni.ResponseWriter, time.Duration, string) *logrusx.Logger
    37  
    38  	logStarting bool
    39  
    40  	clock timer
    41  
    42  	logLevel logrus.Level
    43  
    44  	// Silence log for specific URL paths
    45  	silencePaths map[string]bool
    46  
    47  	sync.RWMutex
    48  }
    49  
    50  // NewMiddleware returns a new *Middleware, yay!
    51  func NewMiddleware() *Middleware {
    52  	return NewCustomMiddleware(logrus.InfoLevel, &logrus.TextFormatter{}, "web")
    53  }
    54  
    55  // NewCustomMiddleware builds a *Middleware with the given level and formatter
    56  func NewCustomMiddleware(level logrus.Level, formatter logrus.Formatter, name string) *Middleware {
    57  	log := logrusx.New(name, "", logrusx.ForceFormatter(formatter), logrusx.ForceLevel(level))
    58  	return &Middleware{
    59  		Logger: log,
    60  		Name:   name,
    61  		Before: DefaultBefore,
    62  		After:  DefaultAfter,
    63  
    64  		logLevel:     logrus.InfoLevel,
    65  		logStarting:  true,
    66  		clock:        &realClock{},
    67  		silencePaths: map[string]bool{},
    68  	}
    69  }
    70  
    71  // NewMiddlewareFromLogger returns a new *Middleware which writes to a given logrus logger.
    72  func NewMiddlewareFromLogger(logger *logrusx.Logger, name string) *Middleware {
    73  	return &Middleware{
    74  		Logger: logger,
    75  		Name:   name,
    76  		Before: DefaultBefore,
    77  		After:  DefaultAfter,
    78  
    79  		logLevel:     logrus.InfoLevel,
    80  		logStarting:  true,
    81  		clock:        &realClock{},
    82  		silencePaths: map[string]bool{},
    83  	}
    84  }
    85  
    86  // SetLogStarting accepts a bool to control the logging of "started handling
    87  // request" prior to passing to the next middleware
    88  func (m *Middleware) SetLogStarting(v bool) {
    89  	m.logStarting = v
    90  }
    91  
    92  // ExcludePaths adds new URL paths to be ignored during logging. The URL u is parsed, hence the returned error
    93  func (m *Middleware) ExcludePaths(paths ...string) *Middleware {
    94  	for _, path := range paths {
    95  		m.Lock()
    96  		m.silencePaths[path] = true
    97  		m.Unlock()
    98  	}
    99  	return m
   100  }
   101  
   102  func (m *Middleware) ServeHTTP(rw http.ResponseWriter, r *http.Request, next http.HandlerFunc) {
   103  	if m.Before == nil {
   104  		m.Before = DefaultBefore
   105  	}
   106  
   107  	if m.After == nil {
   108  		m.After = DefaultAfter
   109  	}
   110  
   111  	logLevel := m.logLevel
   112  	m.RLock()
   113  	if _, ok := m.silencePaths[r.URL.Path]; ok {
   114  		logLevel = logrus.TraceLevel
   115  	}
   116  	m.RUnlock()
   117  
   118  	start := m.clock.Now()
   119  
   120  	// Try to get the real IP
   121  	remoteAddr := r.RemoteAddr
   122  	if realIP := r.Header.Get("X-Real-IP"); realIP != "" {
   123  		remoteAddr = realIP
   124  	}
   125  
   126  	entry := m.Logger.NewEntry()
   127  
   128  	entry = m.Before(entry, r, remoteAddr)
   129  
   130  	if m.logStarting {
   131  		entry.Log(logLevel, "started handling request")
   132  	}
   133  
   134  	next(rw, r)
   135  
   136  	latency := m.clock.Since(start)
   137  	res := rw.(negroni.ResponseWriter)
   138  
   139  	m.After(entry, r, res, latency, m.Name).Log(logLevel, "completed handling request")
   140  }
   141  
   142  // BeforeFunc is the func type used to modify or replace the *logrusx.Logger prior
   143  // to calling the next func in the middleware chain
   144  type BeforeFunc func(*logrusx.Logger, *http.Request, string) *logrusx.Logger
   145  
   146  // AfterFunc is the func type used to modify or replace the *logrusx.Logger after
   147  // calling the next func in the middleware chain
   148  type AfterFunc func(*logrusx.Logger, negroni.ResponseWriter, time.Duration, string) *logrusx.Logger
   149  
   150  // DefaultBefore is the default func assigned to *Middleware.Before
   151  func DefaultBefore(entry *logrusx.Logger, req *http.Request, remoteAddr string) *logrusx.Logger {
   152  	return entry.WithRequest(req)
   153  }
   154  
   155  // DefaultAfter is the default func assigned to *Middleware.After
   156  func DefaultAfter(entry *logrusx.Logger, req *http.Request, res negroni.ResponseWriter, latency time.Duration, name string) *logrusx.Logger {
   157  	return entry.WithRequest(req).WithField("http_response", map[string]interface{}{
   158  		"status":      res.Status(),
   159  		"text_status": http.StatusText(res.Status()),
   160  		"took":        latency,
   161  	})
   162  }
   163
View as plain text