oauth2_proxy/pkg/logger/logger.go

485 lines
12 KiB
Go
Raw Normal View History

package logger
import (
"fmt"
"io"
"net"
"net/http"
"net/url"
"os"
"runtime"
"sync"
"text/template"
"time"
)
2019-02-15 18:07:25 +00:00
// AuthStatus defines the different types of auth logging that occur
type AuthStatus string
const (
2019-02-15 18:07:25 +00:00
// DefaultStandardLoggingFormat defines the default standard log format
DefaultStandardLoggingFormat = "[{{.Timestamp}}] [{{.File}}] {{.Message}}"
2019-02-15 18:07:25 +00:00
// DefaultAuthLoggingFormat defines the default auth log format
DefaultAuthLoggingFormat = "{{.Client}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}}"
// DefaultRequestLoggingFormat defines the default request log format
DefaultRequestLoggingFormat = "{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}"
2019-02-15 18:07:25 +00:00
// AuthSuccess indicates that an auth attempt has succeeded explicitly
AuthSuccess AuthStatus = "AuthSuccess"
2019-02-15 18:07:25 +00:00
// AuthFailure indicates that an auth attempt has failed explicitly
AuthFailure AuthStatus = "AuthFailure"
2019-02-15 18:07:25 +00:00
// AuthError indicates that an auth attempt has failed due to an error
AuthError AuthStatus = "AuthError"
// Llongfile flag to log full file name and line number: /a/b/c/d.go:23
Llongfile = 1 << iota
// Lshortfile flag to log final file name element and line number: d.go:23. overrides Llongfile
Lshortfile
// LUTC flag to log UTC datetime rather than the local time zone
LUTC
// LstdFlags flag for initial values for the logger
LstdFlags = Lshortfile
)
// These are the containers for all values that are available as variables in the logging formats.
// All values are pre-formatted strings so it is easy to use them in the format string.
type stdLogMessageData struct {
Timestamp,
File,
Message string
}
type authLogMessageData struct {
Client,
Host,
Protocol,
RequestMethod,
Timestamp,
UserAgent,
Username,
Status,
Message string
}
type reqLogMessageData struct {
Client,
Host,
Protocol,
RequestDuration,
RequestMethod,
RequestURI,
ResponseSize,
StatusCode,
Timestamp,
Upstream,
UserAgent,
Username string
}
2019-02-15 18:07:25 +00:00
// A Logger represents an active logging object that generates lines of
// output to an io.Writer passed through a formatter. Each logging
// operation makes a single call to the Writer's Write method. A Logger
// can be used simultaneously from multiple goroutines; it guarantees to
// serialize access to the Writer.
type Logger struct {
mu sync.Mutex
flag int
writer io.Writer
stdEnabled bool
authEnabled bool
reqEnabled bool
silentPing bool
pingPath string
stdLogTemplate *template.Template
authTemplate *template.Template
reqTemplate *template.Template
}
// New creates a new Standarderr Logger.
func New(flag int) *Logger {
return &Logger{
writer: os.Stderr,
flag: flag,
stdEnabled: true,
authEnabled: true,
reqEnabled: true,
silentPing: false,
pingPath: "/ping",
stdLogTemplate: template.Must(template.New("std-log").Parse(DefaultStandardLoggingFormat)),
authTemplate: template.Must(template.New("auth-log").Parse(DefaultAuthLoggingFormat)),
reqTemplate: template.Must(template.New("req-log").Parse(DefaultRequestLoggingFormat)),
}
}
var std = New(LstdFlags)
// Output a standard log template with a simple message.
// Write a final newline at the end of every message.
func (l *Logger) Output(calldepth int, message string) {
if !l.stdEnabled {
return
}
now := time.Now()
file := "???:0"
if l.flag&(Lshortfile|Llongfile) != 0 {
file = l.GetFileLineString(calldepth + 1)
}
l.mu.Lock()
defer l.mu.Unlock()
l.stdLogTemplate.Execute(l.writer, stdLogMessageData{
Timestamp: FormatTimestamp(now),
File: file,
Message: message,
})
l.writer.Write([]byte("\n"))
}
2019-02-15 18:07:25 +00:00
// PrintAuth writes auth info to the logger. Requires an http.Request to
// log request details. Remaining arguments are handled in the manner of
// fmt.Sprintf. Writes a final newline to the end of every message.
func (l *Logger) PrintAuth(username string, req *http.Request, status AuthStatus, format string, a ...interface{}) {
if !l.authEnabled {
return
}
now := time.Now()
if username == "" {
username = "-"
}
client := GetClient(req)
l.mu.Lock()
defer l.mu.Unlock()
l.authTemplate.Execute(l.writer, authLogMessageData{
Client: client,
Host: req.Host,
Protocol: req.Proto,
RequestMethod: req.Method,
Timestamp: FormatTimestamp(now),
UserAgent: fmt.Sprintf("%q", req.UserAgent()),
Username: username,
Status: fmt.Sprintf("%s", status),
Message: fmt.Sprintf(format, a...),
})
l.writer.Write([]byte("\n"))
}
2019-02-15 18:07:25 +00:00
// PrintReq writes request details to the Logger using the http.Request,
// url, and timestamp of the request. Writes a final newline to the end
// of every message.
func (l *Logger) PrintReq(username, upstream string, req *http.Request, url url.URL, ts time.Time, status int, size int) {
if !l.reqEnabled {
return
}
if url.Path == l.pingPath && l.silentPing {
return
}
duration := float64(time.Now().Sub(ts)) / float64(time.Second)
if username == "" {
username = "-"
}
if upstream == "" {
upstream = "-"
}
if url.User != nil && username == "-" {
if name := url.User.Username(); name != "" {
username = name
}
}
client := GetClient(req)
l.mu.Lock()
defer l.mu.Unlock()
l.reqTemplate.Execute(l.writer, reqLogMessageData{
Client: client,
Host: req.Host,
Protocol: req.Proto,
RequestDuration: fmt.Sprintf("%0.3f", duration),
RequestMethod: req.Method,
RequestURI: fmt.Sprintf("%q", url.RequestURI()),
ResponseSize: fmt.Sprintf("%d", size),
StatusCode: fmt.Sprintf("%d", status),
Timestamp: FormatTimestamp(ts),
Upstream: upstream,
UserAgent: fmt.Sprintf("%q", req.UserAgent()),
Username: username,
})
l.writer.Write([]byte("\n"))
}
2019-02-15 18:07:25 +00:00
// GetFileLineString will find the caller file and line number
// taking in to account the calldepth to iterate up the stack
// to find the non-logging call location.
func (l *Logger) GetFileLineString(calldepth int) string {
var file string
var line int
var ok bool
_, file, line, ok = runtime.Caller(calldepth)
if !ok {
file = "???"
line = 0
}
if l.flag&Lshortfile != 0 {
short := file
for i := len(file) - 1; i > 0; i-- {
if file[i] == '/' {
short = file[i+1:]
break
}
}
file = short
}
return fmt.Sprintf("%s:%d", file, line)
}
2019-02-15 18:07:25 +00:00
// GetClient parses an HTTP request for the client/remote IP address.
func GetClient(req *http.Request) string {
client := req.Header.Get("X-Real-IP")
if client == "" {
client = req.RemoteAddr
}
if c, _, err := net.SplitHostPort(client); err == nil {
client = c
}
return client
}
2019-02-15 18:07:25 +00:00
// FormatTimestamp returns a formatted timestamp.
func (l *Logger) FormatTimestamp(ts time.Time) string {
if l.flag&LUTC != 0 {
ts = ts.UTC()
}
return ts.Format("2006/01/02 15:04:05")
}
// Flags returns the output flags for the logger.
func (l *Logger) Flags() int {
l.mu.Lock()
defer l.mu.Unlock()
return l.flag
}
// SetFlags sets the output flags for the logger.
func (l *Logger) SetFlags(flag int) {
l.mu.Lock()
defer l.mu.Unlock()
l.flag = flag
}
2019-02-15 18:07:25 +00:00
// SetStandardEnabled enables or disables standard logging.
func (l *Logger) SetStandardEnabled(e bool) {
l.mu.Lock()
defer l.mu.Unlock()
l.stdEnabled = e
}
2019-02-15 18:07:25 +00:00
// SetAuthEnabled enables or disables auth logging.
func (l *Logger) SetAuthEnabled(e bool) {
l.mu.Lock()
defer l.mu.Unlock()
l.authEnabled = e
}
2019-02-15 18:07:25 +00:00
// SetReqEnabled enabled or disables request logging.
func (l *Logger) SetReqEnabled(e bool) {
l.mu.Lock()
defer l.mu.Unlock()
l.reqEnabled = e
}
// SetPingPath sets the ping path.
func (l *Logger) SetPingPath(s string) {
l.mu.Lock()
defer l.mu.Unlock()
l.pingPath = s
}
// SetSilentPing disables ping request logging.
func (l *Logger) SetSilentPing(e bool) {
l.mu.Lock()
defer l.mu.Unlock()
l.silentPing = e
}
2019-02-15 18:07:25 +00:00
// SetStandardTemplate sets the template for standard logging.
func (l *Logger) SetStandardTemplate(t string) {
l.mu.Lock()
defer l.mu.Unlock()
l.stdLogTemplate = template.Must(template.New("std-log").Parse(t))
}
2019-02-15 18:07:25 +00:00
// SetAuthTemplate sets the template for auth logging.
func (l *Logger) SetAuthTemplate(t string) {
l.mu.Lock()
defer l.mu.Unlock()
l.authTemplate = template.Must(template.New("auth-log").Parse(t))
}
2019-02-15 18:07:25 +00:00
// SetReqTemplate sets the template for request logging.
func (l *Logger) SetReqTemplate(t string) {
l.mu.Lock()
defer l.mu.Unlock()
l.reqTemplate = template.Must(template.New("req-log").Parse(t))
}
// These functions utilize the standard logger.
2019-02-15 18:07:25 +00:00
// FormatTimestamp returns a formatted timestamp for the standard logger.
func FormatTimestamp(ts time.Time) string {
return std.FormatTimestamp(ts)
}
// Flags returns the output flags for the standard logger.
func Flags() int {
return std.Flags()
}
// SetFlags sets the output flags for the standard logger.
func SetFlags(flag int) {
std.SetFlags(flag)
}
// SetOutput sets the output destination for the standard logger.
func SetOutput(w io.Writer) {
std.mu.Lock()
defer std.mu.Unlock()
std.writer = w
}
2019-02-15 18:07:25 +00:00
// SetStandardEnabled enables or disables standard logging for the
// standard logger.
func SetStandardEnabled(e bool) {
std.SetStandardEnabled(e)
}
2019-02-15 18:07:25 +00:00
// SetAuthEnabled enables or disables auth logging for the standard
// logger.
func SetAuthEnabled(e bool) {
std.SetAuthEnabled(e)
}
2019-02-15 18:07:25 +00:00
// SetReqEnabled enables or disables request logging for the
// standard logger.
func SetReqEnabled(e bool) {
std.SetReqEnabled(e)
}
// SetPingPath sets the healthcheck endpoint path.
// FIXME: Seems wrong to define this
func SetPingPath(s string) {
std.SetPingPath(s)
}
// SetSilentPing disables request logging for the ping endpoint.
func SetSilentPing(e bool) {
std.SetSilentPing(e)
}
2019-02-15 18:07:25 +00:00
// SetStandardTemplate sets the template for standard logging for
// the standard logger.
func SetStandardTemplate(t string) {
std.SetStandardTemplate(t)
}
2019-02-15 18:07:25 +00:00
// SetAuthTemplate sets the template for auth logging for the
// standard logger.
func SetAuthTemplate(t string) {
std.SetAuthTemplate(t)
}
2019-02-15 18:07:25 +00:00
// SetReqTemplate sets the template for request logging for the
// standard logger.
func SetReqTemplate(t string) {
std.SetReqTemplate(t)
}
// Print calls Output to print to the standard logger.
// Arguments are handled in the manner of fmt.Print.
func Print(v ...interface{}) {
std.Output(2, fmt.Sprint(v...))
}
// Printf calls Output to print to the standard logger.
// Arguments are handled in the manner of fmt.Printf.
func Printf(format string, v ...interface{}) {
std.Output(2, fmt.Sprintf(format, v...))
}
// Println calls Output to print to the standard logger.
// Arguments are handled in the manner of fmt.Println.
func Println(v ...interface{}) {
std.Output(2, fmt.Sprintln(v...))
}
// Fatal is equivalent to Print() followed by a call to os.Exit(1).
func Fatal(v ...interface{}) {
std.Output(2, fmt.Sprint(v...))
os.Exit(1)
}
// Fatalf is equivalent to Printf() followed by a call to os.Exit(1).
func Fatalf(format string, v ...interface{}) {
std.Output(2, fmt.Sprintf(format, v...))
os.Exit(1)
}
// Fatalln is equivalent to Println() followed by a call to os.Exit(1).
func Fatalln(v ...interface{}) {
std.Output(2, fmt.Sprintln(v...))
os.Exit(1)
}
// Panic is equivalent to Print() followed by a call to panic().
func Panic(v ...interface{}) {
s := fmt.Sprint(v...)
std.Output(2, s)
panic(s)
}
// Panicf is equivalent to Printf() followed by a call to panic().
func Panicf(format string, v ...interface{}) {
s := fmt.Sprintf(format, v...)
std.Output(2, s)
panic(s)
}
// Panicln is equivalent to Println() followed by a call to panic().
func Panicln(v ...interface{}) {
s := fmt.Sprintln(v...)
std.Output(2, s)
panic(s)
}
// PrintAuthf writes authentication details to the standard logger.
// Arguments are handled in the manner of fmt.Printf.
func PrintAuthf(username string, req *http.Request, status AuthStatus, format string, a ...interface{}) {
std.PrintAuth(username, req, status, format, a...)
}
2019-02-15 18:07:25 +00:00
// PrintReq writes request details to the standard logger.
func PrintReq(username, upstream string, req *http.Request, url url.URL, ts time.Time, status int, size int) {
std.PrintReq(username, upstream, req, url, ts, status, size)
}