Auth and standard logging with file rolling

This commit is contained in:
MisterWil 2019-02-10 08:37:45 -08:00
parent dd9781ddfe
commit b46e34be72
23 changed files with 771 additions and 225 deletions

15
Gopkg.lock generated
View File

@ -87,7 +87,10 @@
[[projects]] [[projects]]
digest = "1:3926a4ec9a4ff1a072458451aa2d9b98acd059a45b38f7335d31e06c3d6a0159" digest = "1:3926a4ec9a4ff1a072458451aa2d9b98acd059a45b38f7335d31e06c3d6a0159"
name = "github.com/stretchr/testify" name = "github.com/stretchr/testify"
packages = ["assert"] packages = [
"assert",
"require",
]
pruneopts = "" pruneopts = ""
revision = "69483b4bd14f5845b5a1e55bca19e954e827f1d0" revision = "69483b4bd14f5845b5a1e55bca19e954e827f1d0"
version = "v1.1.4" version = "v1.1.4"
@ -170,6 +173,14 @@
revision = "836bfd95fecc0f1511dd66bdbf2b5b61ab8b00b6" revision = "836bfd95fecc0f1511dd66bdbf2b5b61ab8b00b6"
version = "v1.2.11" version = "v1.2.11"
[[projects]]
digest = "1:11c58e19ff7ce22740423bb933f1ddca3bf575def40d5ac3437ec12871b1648b"
name = "gopkg.in/natefinch/lumberjack.v2"
packages = ["."]
pruneopts = ""
revision = "a96e63847dc3c67d17befa69c303767e2f84e54f"
version = "v2.1"
[[projects]] [[projects]]
digest = "1:be4ed0a2b15944dd777a663681a39260ed05f9c4e213017ed2e2255622c8820c" digest = "1:be4ed0a2b15944dd777a663681a39260ed05f9c4e213017ed2e2255622c8820c"
name = "gopkg.in/square/go-jose.v2" name = "gopkg.in/square/go-jose.v2"
@ -192,12 +203,14 @@
"github.com/mbland/hmacauth", "github.com/mbland/hmacauth",
"github.com/mreiferson/go-options", "github.com/mreiferson/go-options",
"github.com/stretchr/testify/assert", "github.com/stretchr/testify/assert",
"github.com/stretchr/testify/require",
"golang.org/x/crypto/bcrypt", "golang.org/x/crypto/bcrypt",
"golang.org/x/oauth2", "golang.org/x/oauth2",
"golang.org/x/oauth2/google", "golang.org/x/oauth2/google",
"google.golang.org/api/admin/directory/v1", "google.golang.org/api/admin/directory/v1",
"google.golang.org/api/googleapi", "google.golang.org/api/googleapi",
"gopkg.in/fsnotify/fsnotify.v1", "gopkg.in/fsnotify/fsnotify.v1",
"gopkg.in/natefinch/lumberjack.v2",
] ]
solver-name = "gps-cdcl" solver-name = "gps-cdcl"
solver-version = 1 solver-version = 1

View File

@ -38,3 +38,7 @@
[[constraint]] [[constraint]]
branch = "master" branch = "master"
name = "golang.org/x/crypto" name = "golang.org/x/crypto"
[[constraint]]
name = "gopkg.in/natefinch/lumberjack.v2"
version = "2.1.0"

View File

@ -185,6 +185,8 @@ An example [oauth2_proxy.cfg](contrib/oauth2_proxy.cfg.example) config file is i
``` ```
Usage of oauth2_proxy: Usage of oauth2_proxy:
-approval-prompt string: OAuth approval_prompt (default "force") -approval-prompt string: OAuth approval_prompt (default "force")
-auth-logging: Log authentication attempts (default true)
-auth-logging-format string: Template for authentication log lines (see "Logging Configuration" paragraph below)
-authenticated-emails-file string: authenticate against emails via file (one per line) -authenticated-emails-file string: authenticate against emails via file (one per line)
-azure-tenant string: go to a tenant-specific or common (tenant-independent) endpoint. (default "common") -azure-tenant string: go to a tenant-specific or common (tenant-independent) endpoint. (default "common")
-basic-auth-password string: the password to set when passing the HTTP Basic Auth header -basic-auth-password string: the password to set when passing the HTTP Basic Auth header
@ -210,6 +212,12 @@ Usage of oauth2_proxy:
-htpasswd-file string: additionally authenticate against a htpasswd file. Entries must be created with "htpasswd -s" for SHA encryption -htpasswd-file string: additionally authenticate against a htpasswd file. Entries must be created with "htpasswd -s" for SHA encryption
-http-address string: [http://]<addr>:<port> or unix://<path> to listen on for HTTP clients (default "127.0.0.1:4180") -http-address string: [http://]<addr>:<port> or unix://<path> to listen on for HTTP clients (default "127.0.0.1:4180")
-https-address string: <addr>:<port> to listen on for HTTPS clients (default ":443") -https-address string: <addr>:<port> to listen on for HTTPS clients (default ":443")
-logging-compress: Should rotated log files be compressed using gzip (default false)
-logging-filename string: File to log requests to, empty for stdout (default to stdout)
-logging-local-time: If the time in log files and backup filenames are local or UTC time (default true)
-logging-max-age int: Maximum number of days to retain old log files (default 7)
-logging-max-backups int: Maximum number of old log files to retain; 0 to disable (default 0)
-logging-max-size int: Maximum size in megabytes of the log file before rotation (default 100)
-login-url string: Authentication endpoint -login-url string: Authentication endpoint
-pass-access-token: pass OAuth access_token to upstream via X-Forwarded-Access-Token header -pass-access-token: pass OAuth access_token to upstream via X-Forwarded-Access-Token header
-pass-authorization-header: pass OIDC IDToken to upstream via Authorization Bearer header -pass-authorization-header: pass OIDC IDToken to upstream via Authorization Bearer header
@ -222,7 +230,7 @@ Usage of oauth2_proxy:
-redeem-url string: Token redemption endpoint -redeem-url string: Token redemption endpoint
-redirect-url string: the OAuth Redirect URL. ie: "https://internalapp.yourcompany.com/oauth2/callback" -redirect-url string: the OAuth Redirect URL. ie: "https://internalapp.yourcompany.com/oauth2/callback"
-request-logging: Log requests to stdout (default true) -request-logging: Log requests to stdout (default true)
-request-logging-format: Template for request log lines (see "Logging Format" paragraph below) -request-logging-format: Template for request log lines (see "Logging Configuration" paragraph below)
-resource string: The resource that is protected (Azure AD only) -resource string: The resource that is protected (Azure AD only)
-scope string: OAuth scope specification -scope string: OAuth scope specification
-set-xauthrequest: set X-Auth-Request-User and X-Auth-Request-Email response headers (useful in Nginx auth_request mode) -set-xauthrequest: set X-Auth-Request-User and X-Auth-Request-Email response headers (useful in Nginx auth_request mode)
@ -232,6 +240,8 @@ Usage of oauth2_proxy:
-skip-auth-regex value: bypass authentication for requests path's that match (may be given multiple times) -skip-auth-regex value: bypass authentication for requests path's that match (may be given multiple times)
-skip-provider-button: will skip sign-in-page to directly reach the next step: oauth/start -skip-provider-button: will skip sign-in-page to directly reach the next step: oauth/start
-ssl-insecure-skip-verify: skip validation of certificates presented when using HTTPS -ssl-insecure-skip-verify: skip validation of certificates presented when using HTTPS
-standard-logging: Log standard runtime information (default true)
-standard-logging-format string: Template for standard log lines (see "Logging Configuration" paragraph below)
-tls-cert string: path to certificate file -tls-cert string: path to certificate file
-tls-key string: path to private key file -tls-key string: path to private key file
-upstream value: the http url(s) of the upstream endpoint or file:// paths for static files. Routing is based on the path -upstream value: the http url(s) of the upstream endpoint or file:// paths for static files. Routing is based on the path
@ -361,9 +371,40 @@ following:
- [rc3.org: Using HMAC to authenticate Web service - [rc3.org: Using HMAC to authenticate Web service
requests](http://rc3.org/2011/12/02/using-hmac-to-authenticate-web-service-requests/) requests](http://rc3.org/2011/12/02/using-hmac-to-authenticate-web-service-requests/)
## Logging Format ## Logging Configuration
By default, OAuth2 Proxy logs requests to stdout in a format similar to Apache Combined Log. By default, OAuth2 Proxy logs all output to stdout. Logging can be configured to output to a rotating log file using the `-logging-filename` command.
If logging to a file you can also configure the maximum file size (`-logging-max-size`), age (`-logging-max-age`), max backup logs (`-logging-max-backups`), and if backup logs should be compressed (`-logging-compress`).
There are three different types of logging: standard, authentication, and HTTP requests. These can each be enabled or disabled with `-standard-logging`, `-auth-logging`, and `-request-logging`.
Each type of logging has their own configurable format and variables. By default these formats are similar to the Apache Combined Log.
### Auth Log Format
Authentication logs are logs which are guaranteed to contain a username or email address of a user attempting to authenticate. These logs are output by default in the below format:
```
<REMOTE_ADDRESS> - <user@domain.com> [19/Mar/2015:17:20:19 -0400] [<STATUS>] <MESSAGE>
```
The status block will contain one of the below strings:
- `AuthSuccess` If a user has authenticated successfully by any method
- `AuthFailure` If the user failed to authenticate explicitly
- `AuthError` If there was an unexpected error during authentication
If you require a different format than that, you can configure it with the `-auth-logging-format` flag.
The default format is configured as follows:
```
{{.Client}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}}
```
[See `authLogMessageData` in `logging_handler.go`](./logger/logger.go) for all available variables.
### Request Log Format
HTTP request logs will output by default in the below format:
``` ```
<REMOTE_ADDRESS> - <user@domain.com> [19/Mar/2015:17:20:19 -0400] <HOST_HEADER> GET <UPSTREAM_HOST> "/path/" HTTP/1.1 "<USER_AGENT>" <RESPONSE_CODE> <RESPONSE_BYTES> <REQUEST_DURATION> <REMOTE_ADDRESS> - <user@domain.com> [19/Mar/2015:17:20:19 -0400] <HOST_HEADER> GET <UPSTREAM_HOST> "/path/" HTTP/1.1 "<USER_AGENT>" <RESPONSE_CODE> <RESPONSE_BYTES> <REQUEST_DURATION>
@ -376,7 +417,20 @@ The default format is configured as follows:
{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}} {{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}
``` ```
[See `logMessageData` in `logging_handler.go`](./logging_handler.go) for all available variables. [See `requestLogMessageData` in `logging_handler.go`](./logger/logger.go) for all available variables.
### Standard Log Format
All other logging that is not covered by the above two types of logging will be output in this standard logging format. This includes configuration information at startup and errors that occur outside of a session. The default format is below:
```
[19/Mar/2015:17:20:19 -0400] [main.go:40] <MESSAGE>
```
If you require a different format than that, you can configure it with the `-standard-logging-format` flag. The default format is configured as follows:
```
[{{.Timestamp}}] [{{.File}}] {{.Message}}
```
## Adding a new Provider ## Adding a new Provider

View File

@ -4,22 +4,22 @@ import (
"encoding/json" "encoding/json"
"fmt" "fmt"
"io/ioutil" "io/ioutil"
"log"
"net/http" "net/http"
"github.com/bitly/go-simplejson" "github.com/bitly/go-simplejson"
"github.com/pusher/oauth2_proxy/logger"
) )
// Request parses the request body into a simplejson.Json object // Request parses the request body into a simplejson.Json object
func Request(req *http.Request) (*simplejson.Json, error) { func Request(req *http.Request) (*simplejson.Json, error) {
resp, err := http.DefaultClient.Do(req) resp, err := http.DefaultClient.Do(req)
if err != nil { if err != nil {
log.Printf("%s %s %s", req.Method, req.URL, err) logger.Printf("%s %s %s", req.Method, req.URL, err)
return nil, err return nil, err
} }
body, err := ioutil.ReadAll(resp.Body) body, err := ioutil.ReadAll(resp.Body)
resp.Body.Close() resp.Body.Close()
log.Printf("%d %s %s %s", resp.StatusCode, req.Method, req.URL, body) logger.Printf("%d %s %s %s", resp.StatusCode, req.Method, req.URL, body)
if err != nil { if err != nil {
return nil, err return nil, err
} }
@ -37,12 +37,12 @@ func Request(req *http.Request) (*simplejson.Json, error) {
func RequestJSON(req *http.Request, v interface{}) error { func RequestJSON(req *http.Request, v interface{}) error {
resp, err := http.DefaultClient.Do(req) resp, err := http.DefaultClient.Do(req)
if err != nil { if err != nil {
log.Printf("%s %s %s", req.Method, req.URL, err) logger.Printf("%s %s %s", req.Method, req.URL, err)
return err return err
} }
body, err := ioutil.ReadAll(resp.Body) body, err := ioutil.ReadAll(resp.Body)
resp.Body.Close() resp.Body.Close()
log.Printf("%d %s %s %s", resp.StatusCode, req.Method, req.URL, body) logger.Printf("%d %s %s %s", resp.StatusCode, req.Method, req.URL, body)
if err != nil { if err != nil {
return err return err
} }

View File

@ -18,8 +18,18 @@
# "http://127.0.0.1:8080/" # "http://127.0.0.1:8080/"
# ] # ]
## Log requests to stdout ## Logging configuration
#logging_filename = ""
#logging_max_size = 100
#logging_max_age = 7
#logging_local_time = true
#logging_compress = false
#standard_logging = true
#standard_logging_format = "[{{.Timestamp}}] [{{.File}}] {{.Message}}"
#request_logging = true #request_logging = true
#request_logging_format = "{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}"
#auth_logging = true
#auth_logging_format = "{{.Client}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}}"
## pass HTTP Basic Auth, X-Forwarded-User and X-Forwarded-Email information to upstream ## pass HTTP Basic Auth, X-Forwarded-User and X-Forwarded-Email information to upstream
# pass_basic_auth = true # pass_basic_auth = true

View File

@ -5,9 +5,9 @@ import (
"encoding/base64" "encoding/base64"
"encoding/csv" "encoding/csv"
"io" "io"
"log"
"os" "os"
"github.com/pusher/oauth2_proxy/logger"
"golang.org/x/crypto/bcrypt" "golang.org/x/crypto/bcrypt"
) )
@ -67,6 +67,6 @@ func (h *HtpasswdFile) Validate(user string, password string) bool {
return bcrypt.CompareHashAndPassword([]byte(realPassword), []byte(password)) == nil return bcrypt.CompareHashAndPassword([]byte(realPassword), []byte(password)) == nil
} }
log.Printf("Invalid htpasswd entry for %s. Must be a SHA or bcrypt entry.", user) logger.Printf("Invalid htpasswd entry for %s. Must be a SHA or bcrypt entry.", user)
return false return false
} }

21
http.go
View File

@ -2,11 +2,12 @@ package main
import ( import (
"crypto/tls" "crypto/tls"
"log"
"net" "net"
"net/http" "net/http"
"strings" "strings"
"time" "time"
"github.com/pusher/oauth2_proxy/logger"
) )
// Server represents an HTTP server // Server represents an HTTP server
@ -47,17 +48,17 @@ func (s *Server) ServeHTTP() {
listener, err := net.Listen(networkType, listenAddr) listener, err := net.Listen(networkType, listenAddr)
if err != nil { if err != nil {
log.Fatalf("FATAL: listen (%s, %s) failed - %s", networkType, listenAddr, err) logger.Fatalf("FATAL: listen (%s, %s) failed - %s", networkType, listenAddr, err)
} }
log.Printf("HTTP: listening on %s", listenAddr) logger.Printf("HTTP: listening on %s", listenAddr)
server := &http.Server{Handler: s.Handler} server := &http.Server{Handler: s.Handler}
err = server.Serve(listener) err = server.Serve(listener)
if err != nil && !strings.Contains(err.Error(), "use of closed network connection") { if err != nil && !strings.Contains(err.Error(), "use of closed network connection") {
log.Printf("ERROR: http.Serve() - %s", err) logger.Printf("ERROR: http.Serve() - %s", err)
} }
log.Printf("HTTP: closing %s", listener.Addr()) logger.Printf("HTTP: closing %s", listener.Addr())
} }
// ServeHTTPS constructs a net.Listener and starts handling HTTPS requests // ServeHTTPS constructs a net.Listener and starts handling HTTPS requests
@ -75,24 +76,24 @@ func (s *Server) ServeHTTPS() {
config.Certificates = make([]tls.Certificate, 1) config.Certificates = make([]tls.Certificate, 1)
config.Certificates[0], err = tls.LoadX509KeyPair(s.Opts.TLSCertFile, s.Opts.TLSKeyFile) config.Certificates[0], err = tls.LoadX509KeyPair(s.Opts.TLSCertFile, s.Opts.TLSKeyFile)
if err != nil { if err != nil {
log.Fatalf("FATAL: loading tls config (%s, %s) failed - %s", s.Opts.TLSCertFile, s.Opts.TLSKeyFile, err) logger.Fatalf("FATAL: loading tls config (%s, %s) failed - %s", s.Opts.TLSCertFile, s.Opts.TLSKeyFile, err)
} }
ln, err := net.Listen("tcp", addr) ln, err := net.Listen("tcp", addr)
if err != nil { if err != nil {
log.Fatalf("FATAL: listen (%s) failed - %s", addr, err) logger.Fatalf("FATAL: listen (%s) failed - %s", addr, err)
} }
log.Printf("HTTPS: listening on %s", ln.Addr()) logger.Printf("HTTPS: listening on %s", ln.Addr())
tlsListener := tls.NewListener(tcpKeepAliveListener{ln.(*net.TCPListener)}, config) tlsListener := tls.NewListener(tcpKeepAliveListener{ln.(*net.TCPListener)}, config)
srv := &http.Server{Handler: s.Handler} srv := &http.Server{Handler: s.Handler}
err = srv.Serve(tlsListener) err = srv.Serve(tlsListener)
if err != nil && !strings.Contains(err.Error(), "use of closed network connection") { if err != nil && !strings.Contains(err.Error(), "use of closed network connection") {
log.Printf("ERROR: https.Serve() - %s", err) logger.Printf("ERROR: https.Serve() - %s", err)
} }
log.Printf("HTTPS: closing %s", tlsListener.Addr()) logger.Printf("HTTPS: closing %s", tlsListener.Addr())
} }
// tcpKeepAliveListener sets TCP keep-alive timeouts on accepted // tcpKeepAliveListener sets TCP keep-alive timeouts on accepted

447
logger/logger.go Normal file
View File

@ -0,0 +1,447 @@
package logger
import (
"fmt"
"io"
"net"
"net/http"
"net/url"
"os"
"runtime"
"sync"
"text/template"
"time"
)
type AuthStatus string
const (
// Default logging formats
DefaultStandardLoggingFormat = "[{{.Timestamp}}] [{{.File}}] {{.Message}}"
DefaultAuthLoggingFormat = "{{.Client}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}}"
DefaultRequestLoggingFormat = "{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}"
// Auth statuses
AuthSuccess AuthStatus = "AuthSuccess"
AuthFailure AuthStatus = "AuthFailure"
AuthError AuthStatus = "AuthError"
// General logging config
Llongfile = 1 << iota // full file name and line number: /a/b/c/d.go:23
Lshortfile // final file name element and line number: d.go:23. overrides Llongfile
LUTC // use UTC rather than the local time zone
LstdFlags = Lshortfile // initial values for the standard logger
)
// 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
}
type Logger struct {
mu sync.Mutex
flag int
writer io.Writer
stdEnabled bool
authEnabled bool
reqEnabled bool
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,
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)
// Cheap integer to fixed-width decimal ASCII. Give a negative width to avoid zero-padding.
func itoa(buf *[]byte, i int, wid int) {
// Assemble decimal in reverse order.
var b [20]byte
bp := len(b) - 1
for i >= 10 || wid > 1 {
wid--
q := i / 10
b[bp] = byte('0' + i - q*10)
bp--
i = q
}
// i < 10
b[bp] = byte('0' + i)
*buf = append(*buf, b[bp:]...)
}
// 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"))
}
// Print auth details to the logger. Requires an http.Request to log 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"))
}
// Print HTTP request details to the Logger.
// 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
}
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"))
}
// Obtains file and line number info for the standard output log
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)
}
// Parse an HTTP request for the client/remote IP
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
}
// 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
}
// Set all logging enabled for the logger.
func (l *Logger) SetStandardEnabled(e bool) {
l.mu.Lock()
defer l.mu.Unlock()
l.stdEnabled = e
}
// Set auth logging enabled for the standard logger
func (l *Logger) SetAuthEnabled(e bool) {
l.mu.Lock()
defer l.mu.Unlock()
l.authEnabled = e
}
// Set request logging enabled for the standard logger
func (l *Logger) SetReqEnabled(e bool) {
l.mu.Lock()
defer l.mu.Unlock()
l.reqEnabled = e
}
// Set the output template for the standard logger
func (l *Logger) SetStandardTemplate(t string) {
l.mu.Lock()
defer l.mu.Unlock()
l.stdLogTemplate = template.Must(template.New("std-log").Parse(t))
}
// Set the auth template for the standard logger
func (l *Logger) SetAuthTemplate(t string) {
l.mu.Lock()
defer l.mu.Unlock()
l.authTemplate = template.Must(template.New("auth-log").Parse(t))
}
// Set the request template for the standard logger
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.
// 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
}
// Set output logging enabled for the standard logger
func SetStandardEnabled(e bool) {
std.SetStandardEnabled(e)
}
// Set auth logging enabled for the standard logger
func SetAuthEnabled(e bool) {
std.SetAuthEnabled(e)
}
// Set request logging enabled for the standard logger
func SetReqEnabled(e bool) {
std.SetReqEnabled(e)
}
// Set the output template for the standard logger
func SetStandardTemplate(t string) {
std.SetStandardTemplate(t)
}
// Set the auth template for the standard logger
func SetAuthTemplate(t string) {
std.SetAuthTemplate(t)
}
// Set the request template 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...)
}
// PrintAuthf 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)
}

View File

@ -4,17 +4,10 @@
package main package main
import ( import (
"fmt"
"io"
"net"
"net/http" "net/http"
"net/url"
"text/template"
"time" "time"
)
const ( "github.com/pusher/oauth2_proxy/logger"
defaultRequestLoggingFormat = "{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}"
) )
// responseLogger is wrapper of http.ResponseWriter that keeps track of its HTTP status // responseLogger is wrapper of http.ResponseWriter that keeps track of its HTTP status
@ -82,93 +75,22 @@ func (l *responseLogger) Flush() {
} }
} }
// logMessageData is the container for all values that are available as variables in the request logging format.
// All values are pre-formatted strings so it is easy to use them in the format string.
type logMessageData struct {
Client,
Host,
Protocol,
RequestDuration,
RequestMethod,
RequestURI,
ResponseSize,
StatusCode,
Timestamp,
Upstream,
UserAgent,
Username string
}
// loggingHandler is the http.Handler implementation for LoggingHandlerTo and its friends // loggingHandler is the http.Handler implementation for LoggingHandlerTo and its friends
type loggingHandler struct { type loggingHandler struct {
writer io.Writer
handler http.Handler handler http.Handler
enabled bool
logTemplate *template.Template
} }
// LoggingHandler provides an http.Handler which logs requests to the HTTP server // LoggingHandler provides an http.Handler which logs requests to the HTTP server
func LoggingHandler(out io.Writer, h http.Handler, v bool, requestLoggingTpl string) http.Handler { func LoggingHandler(h http.Handler) http.Handler {
return loggingHandler{ return loggingHandler{
writer: out,
handler: h, handler: h,
enabled: v,
logTemplate: template.Must(template.New("request-log").Parse(requestLoggingTpl)),
} }
} }
func (h loggingHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) { func (h loggingHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) {
t := time.Now() t := time.Now()
url := *req.URL url := *req.URL
logger := &responseLogger{w: w} responseLogger := &responseLogger{w: w}
h.handler.ServeHTTP(logger, req) h.handler.ServeHTTP(responseLogger, req)
if !h.enabled { logger.PrintReq(responseLogger.authInfo, responseLogger.upstream, req, url, t, responseLogger.Status(), responseLogger.Size())
return
}
h.writeLogLine(logger.authInfo, logger.upstream, req, url, t, logger.Status(), logger.Size())
}
// Log entry for req similar to Apache Common Log Format.
// ts is the timestamp with which the entry should be logged.
// status, size are used to provide the response HTTP status and size.
func (h loggingHandler) writeLogLine(username, upstream string, req *http.Request, url url.URL, ts time.Time, status int, size int) {
if username == "" {
username = "-"
}
if upstream == "" {
upstream = "-"
}
if url.User != nil && username == "-" {
if name := url.User.Username(); name != "" {
username = name
}
}
client := req.Header.Get("X-Real-IP")
if client == "" {
client = req.RemoteAddr
}
if c, _, err := net.SplitHostPort(client); err == nil {
client = c
}
duration := float64(time.Now().Sub(ts)) / float64(time.Second)
h.logTemplate.Execute(h.writer, logMessageData{
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: ts.Format("02/Jan/2006:15:04:05 -0700"),
Upstream: upstream,
UserAgent: fmt.Sprintf("%q", req.UserAgent()),
Username: username,
})
h.writer.Write([]byte("\n"))
} }

View File

@ -7,6 +7,8 @@ import (
"net/http/httptest" "net/http/httptest"
"testing" "testing"
"time" "time"
"github.com/pusher/oauth2_proxy/logger"
) )
func TestLoggingHandler_ServeHTTP(t *testing.T) { func TestLoggingHandler_ServeHTTP(t *testing.T) {
@ -16,7 +18,7 @@ func TestLoggingHandler_ServeHTTP(t *testing.T) {
Format, Format,
ExpectedLogMessage string ExpectedLogMessage string
}{ }{
{defaultRequestLoggingFormat, fmt.Sprintf("127.0.0.1 - - [%s] test-server GET - \"/foo/bar\" HTTP/1.1 \"\" 200 4 0.000\n", ts.Format("02/Jan/2006:15:04:05 -0700"))}, {logger.DefaultRequestLoggingFormat, fmt.Sprintf("127.0.0.1 - - [%s] test-server GET - \"/foo/bar\" HTTP/1.1 \"\" 200 4 0.000\n", logger.FormatTimestamp(ts))},
{"{{.RequestMethod}}", "GET\n"}, {"{{.RequestMethod}}", "GET\n"},
} }
@ -26,7 +28,9 @@ func TestLoggingHandler_ServeHTTP(t *testing.T) {
w.Write([]byte("test")) w.Write([]byte("test"))
} }
h := LoggingHandler(buf, http.HandlerFunc(handler), true, test.Format) logger.SetOutput(buf)
logger.SetReqTemplate(test.Format)
h := LoggingHandler(http.HandlerFunc(handler))
r, _ := http.NewRequest("GET", "/foo/bar", nil) r, _ := http.NewRequest("GET", "/foo/bar", nil)
r.RemoteAddr = "127.0.0.1" r.RemoteAddr = "127.0.0.1"

37
main.go
View File

@ -3,7 +3,6 @@ package main
import ( import (
"flag" "flag"
"fmt" "fmt"
"log"
"os" "os"
"runtime" "runtime"
"strings" "strings"
@ -11,14 +10,16 @@ import (
"github.com/BurntSushi/toml" "github.com/BurntSushi/toml"
"github.com/mreiferson/go-options" "github.com/mreiferson/go-options"
"github.com/pusher/oauth2_proxy/logger"
) )
func main() { func main() {
log.SetFlags(log.Ldate | log.Ltime | log.Lshortfile) logger.SetFlags(logger.Lshortfile)
flagSet := flag.NewFlagSet("oauth2_proxy", flag.ExitOnError) flagSet := flag.NewFlagSet("oauth2_proxy", flag.ExitOnError)
emailDomains := StringArray{} emailDomains := StringArray{}
whitelistDomains := StringArray{} whitelistandardomains := StringArray{}
upstreams := StringArray{} upstreams := StringArray{}
skipAuthRegex := StringArray{} skipAuthRegex := StringArray{}
googleGroups := StringArray{} googleGroups := StringArray{}
@ -47,7 +48,7 @@ func main() {
flagSet.Duration("flush-interval", time.Duration(1)*time.Second, "period between response flushing when streaming responses") flagSet.Duration("flush-interval", time.Duration(1)*time.Second, "period between response flushing when streaming responses")
flagSet.Var(&emailDomains, "email-domain", "authenticate emails with the specified domain (may be given multiple times). Use * to authenticate any email") flagSet.Var(&emailDomains, "email-domain", "authenticate emails with the specified domain (may be given multiple times). Use * to authenticate any email")
flagSet.Var(&whitelistDomains, "whitelist-domain", "allowed domains for redirection after authentication. Prefix domain with a . to allow subdomains (eg .example.com)") flagSet.Var(&whitelistandardomains, "whitelist-domain", "allowed domains for redirection after authentication. Prefix domain with a . to allow subdomains (eg .example.com)")
flagSet.String("azure-tenant", "common", "go to a tenant-specific or common (tenant-independent) endpoint.") flagSet.String("azure-tenant", "common", "go to a tenant-specific or common (tenant-independent) endpoint.")
flagSet.String("github-org", "", "restrict logins to members of this organisation") flagSet.String("github-org", "", "restrict logins to members of this organisation")
flagSet.String("github-team", "", "restrict logins to members of this team") flagSet.String("github-team", "", "restrict logins to members of this team")
@ -71,8 +72,21 @@ func main() {
flagSet.Bool("cookie-secure", true, "set secure (HTTPS) cookie flag") flagSet.Bool("cookie-secure", true, "set secure (HTTPS) cookie flag")
flagSet.Bool("cookie-httponly", true, "set HttpOnly cookie flag") flagSet.Bool("cookie-httponly", true, "set HttpOnly cookie flag")
flagSet.Bool("request-logging", true, "Log requests to stdout") flagSet.String("logging-filename", "", "File to log requests to, empty for stdout")
flagSet.String("request-logging-format", defaultRequestLoggingFormat, "Template for log lines") flagSet.Int("logging-max-size", 100, "Maximum size in megabytes of the log file before rotation")
flagSet.Int("logging-max-age", 7, "Maximum number of days to retain old log files")
flagSet.Int("logging-max-backups", 0, "Maximum number of old log files to retain; 0 to disable")
flagSet.Bool("logging-local-time", true, "If the time in log files and backup filenames are local or UTC time")
flagSet.Bool("logging-compress", false, "Should rotated log files be compressed using gzip")
flagSet.Bool("standard-logging", true, "Log standard runtime information")
flagSet.String("standard-logging-format", logger.DefaultStandardLoggingFormat, "Template for standard log lines")
flagSet.Bool("request-logging", true, "Log HTTP requests")
flagSet.String("request-logging-format", logger.DefaultRequestLoggingFormat, "Template for HTTP request log lines")
flagSet.Bool("auth-logging", true, "Log authentication attempts")
flagSet.String("auth-logging-format", logger.DefaultAuthLoggingFormat, "Template for authentication log lines")
flagSet.String("provider", "google", "OAuth provider") flagSet.String("provider", "google", "OAuth provider")
flagSet.String("oidc-issuer-url", "", "OpenID Connect issuer URL (ie: https://accounts.google.com)") flagSet.String("oidc-issuer-url", "", "OpenID Connect issuer URL (ie: https://accounts.google.com)")
@ -99,7 +113,7 @@ func main() {
if *config != "" { if *config != "" {
_, err := toml.DecodeFile(*config, &cfg) _, err := toml.DecodeFile(*config, &cfg)
if err != nil { if err != nil {
log.Fatalf("ERROR: failed to load config file %s - %s", *config, err) logger.Fatalf("ERROR: failed to load config file %s - %s", *config, err)
} }
} }
cfg.LoadEnvForStruct(opts) cfg.LoadEnvForStruct(opts)
@ -107,9 +121,10 @@ func main() {
err := opts.Validate() err := opts.Validate()
if err != nil { if err != nil {
log.Printf("%s", err) logger.Printf("%s", err)
os.Exit(1) os.Exit(1)
} }
validator := NewValidator(opts.EmailDomains, opts.AuthenticatedEmailsFile) validator := NewValidator(opts.EmailDomains, opts.AuthenticatedEmailsFile)
oauthproxy := NewOAuthProxy(opts, validator) oauthproxy := NewOAuthProxy(opts, validator)
@ -122,16 +137,16 @@ func main() {
} }
if opts.HtpasswdFile != "" { if opts.HtpasswdFile != "" {
log.Printf("using htpasswd file %s", opts.HtpasswdFile) logger.Printf("using htpasswd file %s", opts.HtpasswdFile)
oauthproxy.HtpasswdFile, err = NewHtpasswdFromFile(opts.HtpasswdFile) oauthproxy.HtpasswdFile, err = NewHtpasswdFromFile(opts.HtpasswdFile)
oauthproxy.DisplayHtpasswdForm = opts.DisplayHtpasswdForm oauthproxy.DisplayHtpasswdForm = opts.DisplayHtpasswdForm
if err != nil { if err != nil {
log.Fatalf("FATAL: unable to open %s %s", opts.HtpasswdFile, err) logger.Fatalf("FATAL: unable to open %s %s", opts.HtpasswdFile, err)
} }
} }
s := &Server{ s := &Server{
Handler: LoggingHandler(os.Stdout, oauthproxy, opts.RequestLogging, opts.RequestLoggingFormat), Handler: LoggingHandler(oauthproxy),
Opts: opts, Opts: opts,
} }
s.ListenAndServe() s.ListenAndServe()

View File

@ -5,7 +5,6 @@ import (
"errors" "errors"
"fmt" "fmt"
"html/template" "html/template"
"log"
"net" "net"
"net/http" "net/http"
"net/http/httputil" "net/http/httputil"
@ -16,6 +15,7 @@ import (
"github.com/mbland/hmacauth" "github.com/mbland/hmacauth"
"github.com/pusher/oauth2_proxy/cookie" "github.com/pusher/oauth2_proxy/cookie"
"github.com/pusher/oauth2_proxy/logger"
"github.com/pusher/oauth2_proxy/providers" "github.com/pusher/oauth2_proxy/providers"
) )
@ -158,7 +158,7 @@ func NewOAuthProxy(opts *Options, validator func(string) bool) *OAuthProxy {
switch u.Scheme { switch u.Scheme {
case httpScheme, httpsScheme: case httpScheme, httpsScheme:
u.Path = "" u.Path = ""
log.Printf("mapping path %q => upstream %q", path, u) logger.Printf("mapping path %q => upstream %q", path, u)
proxy := NewReverseProxy(u, opts.FlushInterval) proxy := NewReverseProxy(u, opts.FlushInterval)
if !opts.PassHostHeader { if !opts.PassHostHeader {
setProxyUpstreamHostHeader(proxy, u) setProxyUpstreamHostHeader(proxy, u)
@ -171,7 +171,7 @@ func NewOAuthProxy(opts *Options, validator func(string) bool) *OAuthProxy {
if u.Fragment != "" { if u.Fragment != "" {
path = u.Fragment path = u.Fragment
} }
log.Printf("mapping path %q => file system %q", path, u.Path) logger.Printf("mapping path %q => file system %q", path, u.Path)
proxy := NewFileServer(path, u.Path) proxy := NewFileServer(path, u.Path)
serveMux.Handle(path, &UpstreamProxy{path, proxy, nil}) serveMux.Handle(path, &UpstreamProxy{path, proxy, nil})
default: default:
@ -179,26 +179,26 @@ func NewOAuthProxy(opts *Options, validator func(string) bool) *OAuthProxy {
} }
} }
for _, u := range opts.CompiledRegex { for _, u := range opts.CompiledRegex {
log.Printf("compiled skip-auth-regex => %q", u) logger.Printf("compiled skip-auth-regex => %q", u)
} }
redirectURL := opts.redirectURL redirectURL := opts.redirectURL
redirectURL.Path = fmt.Sprintf("%s/callback", opts.ProxyPrefix) redirectURL.Path = fmt.Sprintf("%s/callback", opts.ProxyPrefix)
log.Printf("OAuthProxy configured for %s Client ID: %s", opts.provider.Data().ProviderName, opts.ClientID) logger.Printf("OAuthProxy configured for %s Client ID: %s", opts.provider.Data().ProviderName, opts.ClientID)
refresh := "disabled" refresh := "disabled"
if opts.CookieRefresh != time.Duration(0) { if opts.CookieRefresh != time.Duration(0) {
refresh = fmt.Sprintf("after %s", opts.CookieRefresh) refresh = fmt.Sprintf("after %s", opts.CookieRefresh)
} }
log.Printf("Cookie settings: name:%s secure(https):%v httponly:%v expiry:%s domain:%s refresh:%s", opts.CookieName, opts.CookieSecure, opts.CookieHTTPOnly, opts.CookieExpire, opts.CookieDomain, refresh) logger.Printf("Cookie settings: name:%s secure(https):%v httponly:%v expiry:%s domain:%s refresh:%s", opts.CookieName, opts.CookieSecure, opts.CookieHTTPOnly, opts.CookieExpire, opts.CookieDomain, refresh)
var cipher *cookie.Cipher var cipher *cookie.Cipher
if opts.PassAccessToken || opts.SetAuthorization || opts.PassAuthorization || (opts.CookieRefresh != time.Duration(0)) { if opts.PassAccessToken || opts.SetAuthorization || opts.PassAuthorization || (opts.CookieRefresh != time.Duration(0)) {
var err error var err error
cipher, err = cookie.NewCipher(secretBytes(opts.CookieSecret)) cipher, err = cookie.NewCipher(secretBytes(opts.CookieSecret))
if err != nil { if err != nil {
log.Fatal("cookie-secret error: ", err) logger.Fatal("cookie-secret error: ", err)
} }
} }
@ -400,7 +400,7 @@ func (p *OAuthProxy) makeCookie(req *http.Request, name string, value string, ex
domain = h domain = h
} }
if !strings.HasSuffix(domain, p.CookieDomain) { if !strings.HasSuffix(domain, p.CookieDomain) {
log.Printf("Warning: request host is %q but using configured cookie domain of %q", domain, p.CookieDomain) logger.Printf("Warning: request host is %q but using configured cookie domain of %q", domain, p.CookieDomain)
} }
} }
@ -495,7 +495,6 @@ func (p *OAuthProxy) PingPage(rw http.ResponseWriter) {
// ErrorPage writes an error response // ErrorPage writes an error response
func (p *OAuthProxy) ErrorPage(rw http.ResponseWriter, code int, title string, message string) { func (p *OAuthProxy) ErrorPage(rw http.ResponseWriter, code int, title string, message string) {
log.Printf("ErrorPage %d %s %s", code, title, message)
rw.WriteHeader(code) rw.WriteHeader(code)
t := struct { t := struct {
Title string Title string
@ -554,9 +553,10 @@ func (p *OAuthProxy) ManualSignIn(rw http.ResponseWriter, req *http.Request) (st
} }
// check auth // check auth
if p.HtpasswdFile.Validate(user, passwd) { if p.HtpasswdFile.Validate(user, passwd) {
log.Printf("authenticated %q via HtpasswdFile", user) logger.PrintAuthf(user, req, logger.AuthSuccess, "Successful authentication via HtpasswdFile")
return user, true return user, true
} }
logger.PrintAuthf(user, req, logger.AuthFailure, "Failed authentication via HtpasswdFile; unauthorized")
return "", false return "", false
} }
@ -652,6 +652,7 @@ func (p *OAuthProxy) ServeHTTP(rw http.ResponseWriter, req *http.Request) {
func (p *OAuthProxy) SignIn(rw http.ResponseWriter, req *http.Request) { func (p *OAuthProxy) SignIn(rw http.ResponseWriter, req *http.Request) {
redirect, err := p.GetRedirect(req) redirect, err := p.GetRedirect(req)
if err != nil { if err != nil {
logger.Printf("Error obtaining redirect: %s", err.Error())
p.ErrorPage(rw, 500, "Internal Error", err.Error()) p.ErrorPage(rw, 500, "Internal Error", err.Error())
return return
} }
@ -680,12 +681,14 @@ func (p *OAuthProxy) SignOut(rw http.ResponseWriter, req *http.Request) {
func (p *OAuthProxy) OAuthStart(rw http.ResponseWriter, req *http.Request) { func (p *OAuthProxy) OAuthStart(rw http.ResponseWriter, req *http.Request) {
nonce, err := cookie.Nonce() nonce, err := cookie.Nonce()
if err != nil { if err != nil {
logger.Printf("Error obtaining nonce: %s", err.Error())
p.ErrorPage(rw, 500, "Internal Error", err.Error()) p.ErrorPage(rw, 500, "Internal Error", err.Error())
return return
} }
p.SetCSRFCookie(rw, req, nonce) p.SetCSRFCookie(rw, req, nonce)
redirect, err := p.GetRedirect(req) redirect, err := p.GetRedirect(req)
if err != nil { if err != nil {
logger.Printf("Error obtaining redirect: %s", err.Error())
p.ErrorPage(rw, 500, "Internal Error", err.Error()) p.ErrorPage(rw, 500, "Internal Error", err.Error())
return return
} }
@ -701,24 +704,27 @@ func (p *OAuthProxy) OAuthCallback(rw http.ResponseWriter, req *http.Request) {
// finish the oauth cycle // finish the oauth cycle
err := req.ParseForm() err := req.ParseForm()
if err != nil { if err != nil {
logger.Printf("Error while parsing OAuth callback: %s" + err.Error())
p.ErrorPage(rw, 500, "Internal Error", err.Error()) p.ErrorPage(rw, 500, "Internal Error", err.Error())
return return
} }
errorString := req.Form.Get("error") errorString := req.Form.Get("error")
if errorString != "" { if errorString != "" {
logger.Printf("Error while parsing OAuth callback: %s ", errorString)
p.ErrorPage(rw, 403, "Permission Denied", errorString) p.ErrorPage(rw, 403, "Permission Denied", errorString)
return return
} }
session, err := p.redeemCode(req.Host, req.Form.Get("code")) session, err := p.redeemCode(req.Host, req.Form.Get("code"))
if err != nil { if err != nil {
log.Printf("%s error redeeming code %s", remoteAddr, err) logger.Printf("Error while parsing OAuth callback: %s ", errorString)
p.ErrorPage(rw, 500, "Internal Error", "Internal Error") p.ErrorPage(rw, 500, "Internal Error", "Internal Error")
return return
} }
s := strings.SplitN(req.Form.Get("state"), ":", 2) s := strings.SplitN(req.Form.Get("state"), ":", 2)
if len(s) != 2 { if len(s) != 2 {
logger.Printf("Error while parsing OAuth state; invalid length")
p.ErrorPage(rw, 500, "Internal Error", "Invalid State") p.ErrorPage(rw, 500, "Internal Error", "Invalid State")
return return
} }
@ -726,12 +732,13 @@ func (p *OAuthProxy) OAuthCallback(rw http.ResponseWriter, req *http.Request) {
redirect := s[1] redirect := s[1]
c, err := req.Cookie(p.CSRFCookieName) c, err := req.Cookie(p.CSRFCookieName)
if err != nil { if err != nil {
logger.PrintAuthf(session.Email, req, logger.AuthFailure, "Failed authentication via oauth2; unable too obtain CSRF cookie")
p.ErrorPage(rw, 403, "Permission Denied", err.Error()) p.ErrorPage(rw, 403, "Permission Denied", err.Error())
return return
} }
p.ClearCSRFCookie(rw, req) p.ClearCSRFCookie(rw, req)
if c.Value != nonce { if c.Value != nonce {
log.Printf("%s csrf token mismatch, potential attack", remoteAddr) logger.PrintAuthf(session.Email, req, logger.AuthFailure, "Failed authentication via oauth2; csrf token mismatch, potential attack")
p.ErrorPage(rw, 403, "Permission Denied", "csrf failed") p.ErrorPage(rw, 403, "Permission Denied", "csrf failed")
return return
} }
@ -742,16 +749,16 @@ func (p *OAuthProxy) OAuthCallback(rw http.ResponseWriter, req *http.Request) {
// set cookie, or deny // set cookie, or deny
if p.Validator(session.Email) && p.provider.ValidateGroup(session.Email) { if p.Validator(session.Email) && p.provider.ValidateGroup(session.Email) {
log.Printf("%s authentication complete %s", remoteAddr, session) logger.PrintAuthf(session.Email, req, logger.AuthSuccess, "Successful authentication via oauth2; %s", session)
err := p.SaveSession(rw, req, session) err := p.SaveSession(rw, req, session)
if err != nil { if err != nil {
log.Printf("%s %s", remoteAddr, err) logger.Printf("%s %s", remoteAddr, err)
p.ErrorPage(rw, 500, "Internal Error", "Internal Error") p.ErrorPage(rw, 500, "Internal Error", "Internal Error")
return return
} }
http.Redirect(rw, req, redirect, 302) http.Redirect(rw, req, redirect, 302)
} else { } else {
log.Printf("%s Permission Denied: %q is unauthorized", remoteAddr, session.Email) logger.PrintAuthf(session.Email, req, logger.AuthSuccess, "Failed authentication via oauth2; unauthorized")
p.ErrorPage(rw, 403, "Permission Denied", "Invalid Account") p.ErrorPage(rw, 403, "Permission Denied", "Invalid Account")
} }
} }
@ -793,16 +800,16 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int
session, sessionAge, err := p.LoadCookiedSession(req) session, sessionAge, err := p.LoadCookiedSession(req)
if err != nil { if err != nil {
log.Printf("%s %s", remoteAddr, err) logger.Printf("Error loading cookied session: %s", err)
} }
if session != nil && sessionAge > p.CookieRefresh && p.CookieRefresh != time.Duration(0) { if session != nil && sessionAge > p.CookieRefresh && p.CookieRefresh != time.Duration(0) {
log.Printf("%s refreshing %s old session cookie for %s (refresh after %s)", remoteAddr, sessionAge, session, p.CookieRefresh) logger.Printf("Refreshing %s old session cookie for %s (refresh after %s)", sessionAge, session, p.CookieRefresh)
saveSession = true saveSession = true
} }
var ok bool var ok bool
if ok, err = p.provider.RefreshSessionIfNeeded(session); err != nil { if ok, err = p.provider.RefreshSessionIfNeeded(session); err != nil {
log.Printf("%s removing session. error refreshing access token %s %s", remoteAddr, err, session) logger.Printf("%s removing session. error refreshing access token %s %s", remoteAddr, err, session)
clearSession = true clearSession = true
session = nil session = nil
} else if ok { } else if ok {
@ -811,7 +818,7 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int
} }
if session != nil && session.IsExpired() { if session != nil && session.IsExpired() {
log.Printf("%s removing session. token expired %s", remoteAddr, session) logger.Printf("Removing session; token expired %s", session)
session = nil session = nil
saveSession = false saveSession = false
clearSession = true clearSession = true
@ -819,7 +826,7 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int
if saveSession && !revalidated && session != nil && session.AccessToken != "" { if saveSession && !revalidated && session != nil && session.AccessToken != "" {
if !p.provider.ValidateSessionState(session) { if !p.provider.ValidateSessionState(session) {
log.Printf("%s removing session. error validating %s", remoteAddr, session) logger.Printf("Removing session; error validating %s", session)
saveSession = false saveSession = false
session = nil session = nil
clearSession = true clearSession = true
@ -827,7 +834,7 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int
} }
if session != nil && session.Email != "" && !p.Validator(session.Email) { if session != nil && session.Email != "" && !p.Validator(session.Email) {
log.Printf("%s Permission Denied: removing session %s", remoteAddr, session) logger.Printf(session.Email, req, logger.AuthFailure, "Failed authentication via session; removing session %s", session)
session = nil session = nil
saveSession = false saveSession = false
clearSession = true clearSession = true
@ -836,7 +843,7 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int
if saveSession && session != nil { if saveSession && session != nil {
err = p.SaveSession(rw, req, session) err = p.SaveSession(rw, req, session)
if err != nil { if err != nil {
log.Printf("%s %s", remoteAddr, err) logger.PrintAuthf(session.Email, req, logger.AuthError, "Save session error %s", err)
return http.StatusInternalServerError return http.StatusInternalServerError
} }
} }
@ -847,9 +854,6 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int
if session == nil { if session == nil {
session, err = p.CheckBasicAuth(req) session, err = p.CheckBasicAuth(req)
if err != nil {
log.Printf("%s %s", remoteAddr, err)
}
} }
if session == nil { if session == nil {
@ -921,9 +925,10 @@ func (p *OAuthProxy) CheckBasicAuth(req *http.Request) (*providers.SessionState,
return nil, fmt.Errorf("invalid format %s", b) return nil, fmt.Errorf("invalid format %s", b)
} }
if p.HtpasswdFile.Validate(pair[0], pair[1]) { if p.HtpasswdFile.Validate(pair[0], pair[1]) {
log.Printf("authenticated %q via basic auth", pair[0]) logger.PrintAuthf(pair[0], req, logger.AuthSuccess, "Successful authentication via basic auth")
return &providers.SessionState{User: pair[0]}, nil return &providers.SessionState{User: pair[0]}, nil
} }
logger.PrintAuthf(pair[0], req, logger.AuthFailure, "Failed authentication via basic auth; not in Htpasswd file")
return nil, fmt.Errorf("%s not in HtpasswdFile", pair[0]) return nil, fmt.Errorf("%s not in HtpasswdFile", pair[0])
} }

View File

@ -5,7 +5,6 @@ import (
"encoding/base64" "encoding/base64"
"io" "io"
"io/ioutil" "io/ioutil"
"log"
"net" "net"
"net/http" "net/http"
"net/http/httptest" "net/http/httptest"
@ -16,13 +15,14 @@ import (
"time" "time"
"github.com/mbland/hmacauth" "github.com/mbland/hmacauth"
"github.com/pusher/oauth2_proxy/logger"
"github.com/pusher/oauth2_proxy/providers" "github.com/pusher/oauth2_proxy/providers"
"github.com/stretchr/testify/assert" "github.com/stretchr/testify/assert"
"github.com/stretchr/testify/require" "github.com/stretchr/testify/require"
) )
func init() { func init() {
log.SetFlags(log.Ldate | log.Ltime | log.Lshortfile) logger.SetFlags(logger.Lshortfile)
} }
@ -185,7 +185,7 @@ func (tp *TestProvider) ValidateSessionState(session *providers.SessionState) bo
func TestBasicAuthPassword(t *testing.T) { func TestBasicAuthPassword(t *testing.T) {
providerServer := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { providerServer := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
log.Printf("%#v", r) logger.Printf("%#v", r)
var payload string var payload string
switch r.URL.Path { switch r.URL.Path {
case "/oauth/token": case "/oauth/token":
@ -277,7 +277,7 @@ func NewPassAccessTokenTest(opts PassAccessTokenTestOptions) *PassAccessTokenTes
t.providerServer = httptest.NewServer( t.providerServer = httptest.NewServer(
http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
log.Printf("%#v", r) logger.Printf("%#v", r)
var payload string var payload string
switch r.URL.Path { switch r.URL.Path {
case "/oauth/token": case "/oauth/token":

View File

@ -15,7 +15,9 @@ import (
oidc "github.com/coreos/go-oidc" oidc "github.com/coreos/go-oidc"
"github.com/mbland/hmacauth" "github.com/mbland/hmacauth"
"github.com/pusher/oauth2_proxy/logger"
"github.com/pusher/oauth2_proxy/providers" "github.com/pusher/oauth2_proxy/providers"
lumberjack "gopkg.in/natefinch/lumberjack.v2"
) )
// Options holds Configuration Options that can be set by Command Line Flag, // Options holds Configuration Options that can be set by Command Line Flag,
@ -79,8 +81,19 @@ type Options struct {
Scope string `flag:"scope" cfg:"scope"` Scope string `flag:"scope" cfg:"scope"`
ApprovalPrompt string `flag:"approval-prompt" cfg:"approval_prompt"` ApprovalPrompt string `flag:"approval-prompt" cfg:"approval_prompt"`
// Configuration values for logging
LoggingFilename string `flag:"logging-filename" cfg:"logging_filename"`
LoggingMaxSize int `flag:"logging-max-size" cfg:"logging_max_size"`
LoggingMaxAge int `flag:"logging-max-age" cfg:"logging_max_age"`
LoggingMaxBackups int `flag:"logging-max-backups" cfg:"logging_max_backups"`
LoggingLocalTime bool `flag:"logging-local-time" cfg:"logging_local_time"`
LoggingCompress bool `flag:"logging-compress" cfg:"logging_compress"`
StandardLogging bool `flag:"standard-logging" cfg:"standard_logging"`
StandardLoggingFormat string `flag:"standard-logging-format" cfg:"standard_logging_format"`
RequestLogging bool `flag:"request-logging" cfg:"request_logging"` RequestLogging bool `flag:"request-logging" cfg:"request_logging"`
RequestLoggingFormat string `flag:"request-logging-format" cfg:"request_logging_format"` RequestLoggingFormat string `flag:"request-logging-format" cfg:"request_logging_format"`
AuthLogging bool `flag:"auth-logging" cfg:"auth_logging"`
AuthLoggingFormat string `flag:"auth-logging-format" cfg:"auth_logging_format"`
SignatureKey string `flag:"signature-key" cfg:"signature_key" env:"OAUTH2_PROXY_SIGNATURE_KEY"` SignatureKey string `flag:"signature-key" cfg:"signature_key" env:"OAUTH2_PROXY_SIGNATURE_KEY"`
@ -120,8 +133,18 @@ func NewOptions() *Options {
SetAuthorization: false, SetAuthorization: false,
PassAuthorization: false, PassAuthorization: false,
ApprovalPrompt: "force", ApprovalPrompt: "force",
LoggingFilename: "",
LoggingMaxSize: 100,
LoggingMaxAge: 7,
LoggingMaxBackups: 0,
LoggingLocalTime: true,
LoggingCompress: false,
StandardLogging: true,
StandardLoggingFormat: logger.DefaultStandardLoggingFormat,
RequestLogging: true, RequestLogging: true,
RequestLoggingFormat: defaultRequestLoggingFormat, RequestLoggingFormat: logger.DefaultRequestLoggingFormat,
AuthLogging: true,
AuthLoggingFormat: logger.DefaultAuthLoggingFormat,
} }
} }
@ -247,6 +270,7 @@ func (o *Options) Validate() error {
msgs = parseSignatureKey(o, msgs) msgs = parseSignatureKey(o, msgs)
msgs = validateCookieName(o, msgs) msgs = validateCookieName(o, msgs)
msgs = setupLogger(o, msgs)
if len(msgs) != 0 { if len(msgs) != 0 {
return fmt.Errorf("Invalid configuration:\n %s", return fmt.Errorf("Invalid configuration:\n %s",
@ -345,3 +369,49 @@ func secretBytes(secret string) []byte {
} }
return []byte(secret) return []byte(secret)
} }
func setupLogger(o *Options, msgs []string) []string {
// Setup the log file
if len(o.LoggingFilename) > 0 {
// Validate that the file/dir can be written
file, err := os.OpenFile(o.LoggingFilename, os.O_WRONLY|os.O_CREATE, 0666)
if err != nil {
if os.IsPermission(err) {
return append(msgs, "unable to write to log file: "+o.LoggingFilename)
}
}
file.Close()
logger.Printf("Redirecting logging to file: %s", o.LoggingFilename)
logWriter := &lumberjack.Logger{
Filename: o.LoggingFilename,
MaxSize: o.LoggingMaxSize, // megabytes
MaxAge: o.LoggingMaxAge, // days
MaxBackups: o.LoggingMaxBackups,
LocalTime: o.LoggingLocalTime,
Compress: o.LoggingCompress,
}
logger.SetOutput(logWriter)
}
// Supply a sanity warning to the logger if all logging is disabled
if !o.StandardLogging && !o.AuthLogging && !o.RequestLogging {
logger.Print("Warning: Logging disabled. No further logs will be shown.")
}
// Pass configuration values to the standard logger
logger.SetStandardEnabled(o.StandardLogging)
logger.SetAuthEnabled(o.AuthLogging)
logger.SetReqEnabled(o.RequestLogging)
logger.SetStandardTemplate(o.StandardLoggingFormat)
logger.SetAuthTemplate(o.AuthLoggingFormat)
logger.SetReqTemplate(o.RequestLoggingFormat)
if !o.LoggingLocalTime {
logger.SetFlags(logger.Flags() | logger.LUTC)
}
return msgs
}

View File

@ -3,12 +3,12 @@ package providers
import ( import (
"errors" "errors"
"fmt" "fmt"
"log"
"net/http" "net/http"
"net/url" "net/url"
"github.com/bitly/go-simplejson" "github.com/bitly/go-simplejson"
"github.com/pusher/oauth2_proxy/api" "github.com/pusher/oauth2_proxy/api"
"github.com/pusher/oauth2_proxy/logger"
) )
// AzureProvider represents an Azure based Identity Provider // AzureProvider represents an Azure based Identity Provider
@ -116,12 +116,12 @@ func (p *AzureProvider) GetEmailAddress(s *SessionState) (string, error) {
email, err = json.Get("userPrincipalName").String() email, err = json.Get("userPrincipalName").String()
if err != nil { if err != nil {
log.Printf("failed making request %s", err) logger.Printf("failed making request %s", err)
return "", err return "", err
} }
if email == "" { if email == "" {
log.Printf("failed to get email address") logger.Printf("failed to get email address")
return "", err return "", err
} }

View File

@ -4,12 +4,13 @@ import (
"encoding/json" "encoding/json"
"fmt" "fmt"
"io/ioutil" "io/ioutil"
"log"
"net/http" "net/http"
"net/url" "net/url"
"path" "path"
"strconv" "strconv"
"strings" "strings"
"github.com/pusher/oauth2_proxy/logger"
) )
// GitHubProvider represents an GitHub based Identity Provider // GitHubProvider represents an GitHub based Identity Provider
@ -116,13 +117,13 @@ func (p *GitHubProvider) hasOrg(accessToken string) (bool, error) {
var presentOrgs []string var presentOrgs []string
for _, org := range orgs { for _, org := range orgs {
if p.Org == org.Login { if p.Org == org.Login {
log.Printf("Found Github Organization: %q", org.Login) logger.Printf("Found Github Organization: %q", org.Login)
return true, nil return true, nil
} }
presentOrgs = append(presentOrgs, org.Login) presentOrgs = append(presentOrgs, org.Login)
} }
log.Printf("Missing Organization:%q in %v", p.Org, presentOrgs) logger.Printf("Missing Organization:%q in %v", p.Org, presentOrgs)
return false, nil return false, nil
} }
@ -179,7 +180,7 @@ func (p *GitHubProvider) hasOrgAndTeam(accessToken string) (bool, error) {
ts := strings.Split(p.Team, ",") ts := strings.Split(p.Team, ",")
for _, t := range ts { for _, t := range ts {
if t == team.Slug { if t == team.Slug {
log.Printf("Found Github Organization:%q Team:%q (Name:%q)", team.Org.Login, team.Slug, team.Name) logger.Printf("Found Github Organization:%q Team:%q (Name:%q)", team.Org.Login, team.Slug, team.Name)
return true, nil return true, nil
} }
} }
@ -187,13 +188,13 @@ func (p *GitHubProvider) hasOrgAndTeam(accessToken string) (bool, error) {
} }
} }
if hasOrg { if hasOrg {
log.Printf("Missing Team:%q from Org:%q in teams: %v", p.Team, p.Org, presentTeams) logger.Printf("Missing Team:%q from Org:%q in teams: %v", p.Team, p.Org, presentTeams)
} else { } else {
var allOrgs []string var allOrgs []string
for org := range presentOrgs { for org := range presentOrgs {
allOrgs = append(allOrgs, org) allOrgs = append(allOrgs, org)
} }
log.Printf("Missing Organization:%q in %#v", p.Org, allOrgs) logger.Printf("Missing Organization:%q in %#v", p.Org, allOrgs)
} }
return false, nil return false, nil
} }
@ -241,7 +242,7 @@ func (p *GitHubProvider) GetEmailAddress(s *SessionState) (string, error) {
resp.StatusCode, endpoint.String(), body) resp.StatusCode, endpoint.String(), body)
} }
log.Printf("got %d from %q %s", resp.StatusCode, endpoint.String(), body) logger.Printf("got %d from %q %s", resp.StatusCode, endpoint.String(), body)
if err := json.Unmarshal(body, &emails); err != nil { if err := json.Unmarshal(body, &emails); err != nil {
return "", fmt.Errorf("%s unmarshaling %s", err, body) return "", fmt.Errorf("%s unmarshaling %s", err, body)
@ -291,7 +292,7 @@ func (p *GitHubProvider) GetUserName(s *SessionState) (string, error) {
resp.StatusCode, endpoint.String(), body) resp.StatusCode, endpoint.String(), body)
} }
log.Printf("got %d from %q %s", resp.StatusCode, endpoint.String(), body) logger.Printf("got %d from %q %s", resp.StatusCode, endpoint.String(), body)
if err := json.Unmarshal(body, &user); err != nil { if err := json.Unmarshal(body, &user); err != nil {
return "", fmt.Errorf("%s unmarshaling %s", err, body) return "", fmt.Errorf("%s unmarshaling %s", err, body)

View File

@ -1,11 +1,11 @@
package providers package providers
import ( import (
"log"
"net/http" "net/http"
"net/url" "net/url"
"github.com/pusher/oauth2_proxy/api" "github.com/pusher/oauth2_proxy/api"
"github.com/pusher/oauth2_proxy/logger"
) )
// GitLabProvider represents an GitLab based Identity Provider // GitLabProvider represents an GitLab based Identity Provider
@ -49,12 +49,12 @@ func (p *GitLabProvider) GetEmailAddress(s *SessionState) (string, error) {
req, err := http.NewRequest("GET", req, err := http.NewRequest("GET",
p.ValidateURL.String()+"?access_token="+s.AccessToken, nil) p.ValidateURL.String()+"?access_token="+s.AccessToken, nil)
if err != nil { if err != nil {
log.Printf("failed building request %s", err) logger.Printf("failed building request %s", err)
return "", err return "", err
} }
json, err := api.Request(req) json, err := api.Request(req)
if err != nil { if err != nil {
log.Printf("failed making request %s", err) logger.Printf("failed making request %s", err)
return "", err return "", err
} }
return json.Get("email").String() return json.Get("email").String()

View File

@ -8,12 +8,12 @@ import (
"fmt" "fmt"
"io" "io"
"io/ioutil" "io/ioutil"
"log"
"net/http" "net/http"
"net/url" "net/url"
"strings" "strings"
"time" "time"
"github.com/pusher/oauth2_proxy/logger"
"golang.org/x/oauth2" "golang.org/x/oauth2"
"golang.org/x/oauth2/google" "golang.org/x/oauth2/google"
"google.golang.org/api/admin/directory/v1" "google.golang.org/api/admin/directory/v1"
@ -167,18 +167,18 @@ func (p *GoogleProvider) SetGroupRestriction(groups []string, adminEmail string,
func getAdminService(adminEmail string, credentialsReader io.Reader) *admin.Service { func getAdminService(adminEmail string, credentialsReader io.Reader) *admin.Service {
data, err := ioutil.ReadAll(credentialsReader) data, err := ioutil.ReadAll(credentialsReader)
if err != nil { if err != nil {
log.Fatal("can't read Google credentials file:", err) logger.Fatal("can't read Google credentials file:", err)
} }
conf, err := google.JWTConfigFromJSON(data, admin.AdminDirectoryUserReadonlyScope, admin.AdminDirectoryGroupReadonlyScope) conf, err := google.JWTConfigFromJSON(data, admin.AdminDirectoryUserReadonlyScope, admin.AdminDirectoryGroupReadonlyScope)
if err != nil { if err != nil {
log.Fatal("can't load Google credentials file:", err) logger.Fatal("can't load Google credentials file:", err)
} }
conf.Subject = adminEmail conf.Subject = adminEmail
client := conf.Client(oauth2.NoContext) client := conf.Client(oauth2.NoContext)
adminService, err := admin.New(client) adminService, err := admin.New(client)
if err != nil { if err != nil {
log.Fatal(err) logger.Fatal(err)
} }
return adminService return adminService
} }
@ -186,7 +186,7 @@ func getAdminService(adminEmail string, credentialsReader io.Reader) *admin.Serv
func userInGroup(service *admin.Service, groups []string, email string) bool { func userInGroup(service *admin.Service, groups []string, email string) bool {
user, err := fetchUser(service, email) user, err := fetchUser(service, email)
if err != nil { if err != nil {
log.Printf("error fetching user: %v", err) logger.Printf("error fetching user: %v", err)
return false return false
} }
id := user.Id id := user.Id
@ -196,9 +196,9 @@ func userInGroup(service *admin.Service, groups []string, email string) bool {
members, err := fetchGroupMembers(service, group) members, err := fetchGroupMembers(service, group)
if err != nil { if err != nil {
if err, ok := err.(*googleapi.Error); ok && err.Code == 404 { if err, ok := err.(*googleapi.Error); ok && err.Code == 404 {
log.Printf("error fetching members for group %s: group does not exist", group) logger.Printf("error fetching members for group %s: group does not exist", group)
} else { } else {
log.Printf("error fetching group members: %v", err) logger.Printf("error fetching group members: %v", err)
return false return false
} }
} }
@ -273,7 +273,7 @@ func (p *GoogleProvider) RefreshSessionIfNeeded(s *SessionState) (bool, error) {
origExpiration := s.ExpiresOn origExpiration := s.ExpiresOn
s.AccessToken = newToken s.AccessToken = newToken
s.ExpiresOn = time.Now().Add(duration).Truncate(time.Second) s.ExpiresOn = time.Now().Add(duration).Truncate(time.Second)
log.Printf("refreshed access token %s (expired on %s)", s, origExpiration) logger.Printf("refreshed access token %s (expired on %s)", s, origExpiration)
return true, nil return true, nil
} }

View File

@ -2,11 +2,11 @@ package providers
import ( import (
"io/ioutil" "io/ioutil"
"log"
"net/http" "net/http"
"net/url" "net/url"
"github.com/pusher/oauth2_proxy/api" "github.com/pusher/oauth2_proxy/api"
"github.com/pusher/oauth2_proxy/logger"
) )
// stripToken is a helper function to obfuscate "access_token" // stripToken is a helper function to obfuscate "access_token"
@ -24,14 +24,14 @@ func stripToken(endpoint string) string {
func stripParam(param, endpoint string) string { func stripParam(param, endpoint string) string {
u, err := url.Parse(endpoint) u, err := url.Parse(endpoint)
if err != nil { if err != nil {
log.Printf("error attempting to strip %s: %s", param, err) logger.Printf("error attempting to strip %s: %s", param, err)
return endpoint return endpoint
} }
if u.RawQuery != "" { if u.RawQuery != "" {
values, err := url.ParseQuery(u.RawQuery) values, err := url.ParseQuery(u.RawQuery)
if err != nil { if err != nil {
log.Printf("error attempting to strip %s: %s", param, err) logger.Printf("error attempting to strip %s: %s", param, err)
return u.String() return u.String()
} }
@ -57,18 +57,18 @@ func validateToken(p Provider, accessToken string, header http.Header) bool {
} }
resp, err := api.RequestUnparsedResponse(endpoint, header) resp, err := api.RequestUnparsedResponse(endpoint, header)
if err != nil { if err != nil {
log.Printf("GET %s", stripToken(endpoint)) logger.Printf("GET %s", stripToken(endpoint))
log.Printf("token validation request failed: %s", err) logger.Printf("token validation request failed: %s", err)
return false return false
} }
body, _ := ioutil.ReadAll(resp.Body) body, _ := ioutil.ReadAll(resp.Body)
resp.Body.Close() resp.Body.Close()
log.Printf("%d GET %s %s", resp.StatusCode, stripToken(endpoint), body) logger.Printf("%d GET %s %s", resp.StatusCode, stripToken(endpoint), body)
if resp.StatusCode == 200 { if resp.StatusCode == 200 {
return true return true
} }
log.Printf("token validation request failed: status %d - %s", resp.StatusCode, body) logger.Printf("token validation request failed: status %d - %s", resp.StatusCode, body)
return false return false
} }

View File

@ -2,18 +2,19 @@ package main
import ( import (
"html/template" "html/template"
"log"
"path" "path"
"github.com/pusher/oauth2_proxy/logger"
) )
func loadTemplates(dir string) *template.Template { func loadTemplates(dir string) *template.Template {
if dir == "" { if dir == "" {
return getTemplates() return getTemplates()
} }
log.Printf("using custom template directory %q", dir) logger.Printf("using custom template directory %q", dir)
t, err := template.New("").ParseFiles(path.Join(dir, "sign_in.html"), path.Join(dir, "error.html")) t, err := template.New("").ParseFiles(path.Join(dir, "sign_in.html"), path.Join(dir, "error.html"))
if err != nil { if err != nil {
log.Fatalf("failed parsing template %s", err) logger.Fatalf("failed parsing template %s", err)
} }
return t return t
} }
@ -151,7 +152,7 @@ func getTemplates() *template.Template {
</html> </html>
{{end}}`) {{end}}`)
if err != nil { if err != nil {
log.Fatalf("failed parsing template %s", err) logger.Fatalf("failed parsing template %s", err)
} }
t, err = t.Parse(`{{define "error.html"}} t, err = t.Parse(`{{define "error.html"}}
@ -169,7 +170,7 @@ func getTemplates() *template.Template {
</body> </body>
</html>{{end}}`) </html>{{end}}`)
if err != nil { if err != nil {
log.Fatalf("failed parsing template %s", err) logger.Fatalf("failed parsing template %s", err)
} }
return t return t
} }

View File

@ -3,11 +3,12 @@ package main
import ( import (
"encoding/csv" "encoding/csv"
"fmt" "fmt"
"log"
"os" "os"
"strings" "strings"
"sync/atomic" "sync/atomic"
"unsafe" "unsafe"
"github.com/pusher/oauth2_proxy/logger"
) )
// UserMap holds information from the authenticated emails file // UserMap holds information from the authenticated emails file
@ -22,7 +23,7 @@ func NewUserMap(usersFile string, done <-chan bool, onUpdate func()) *UserMap {
m := make(map[string]bool) m := make(map[string]bool)
atomic.StorePointer(&um.m, unsafe.Pointer(&m)) atomic.StorePointer(&um.m, unsafe.Pointer(&m))
if usersFile != "" { if usersFile != "" {
log.Printf("using authenticated emails file %s", usersFile) logger.Printf("using authenticated emails file %s", usersFile)
WatchForUpdates(usersFile, done, func() { WatchForUpdates(usersFile, done, func() {
um.LoadAuthenticatedEmailsFile() um.LoadAuthenticatedEmailsFile()
onUpdate() onUpdate()
@ -44,7 +45,7 @@ func (um *UserMap) IsValid(email string) (result bool) {
func (um *UserMap) LoadAuthenticatedEmailsFile() { func (um *UserMap) LoadAuthenticatedEmailsFile() {
r, err := os.Open(um.usersFile) r, err := os.Open(um.usersFile)
if err != nil { if err != nil {
log.Fatalf("failed opening authenticated-emails-file=%q, %s", um.usersFile, err) logger.Fatalf("failed opening authenticated-emails-file=%q, %s", um.usersFile, err)
} }
defer r.Close() defer r.Close()
csvReader := csv.NewReader(r) csvReader := csv.NewReader(r)
@ -53,7 +54,7 @@ func (um *UserMap) LoadAuthenticatedEmailsFile() {
csvReader.TrimLeadingSpace = true csvReader.TrimLeadingSpace = true
records, err := csvReader.ReadAll() records, err := csvReader.ReadAll()
if err != nil { if err != nil {
log.Printf("error reading authenticated-emails-file=%q, %s", um.usersFile, err) logger.Printf("error reading authenticated-emails-file=%q, %s", um.usersFile, err)
return return
} }
updated := make(map[string]bool) updated := make(map[string]bool)

View File

@ -3,11 +3,11 @@
package main package main
import ( import (
"log"
"os" "os"
"path/filepath" "path/filepath"
"time" "time"
"github.com/pusher/oauth2_proxy/logger"
fsnotify "gopkg.in/fsnotify/fsnotify.v1" fsnotify "gopkg.in/fsnotify/fsnotify.v1"
) )
@ -24,7 +24,7 @@ func WaitForReplacement(filename string, op fsnotify.Op,
for { for {
if _, err := os.Stat(filename); err == nil { if _, err := os.Stat(filename); err == nil {
if err := watcher.Add(filename); err == nil { if err := watcher.Add(filename); err == nil {
log.Printf("watching resumed for %s", filename) logger.Printf("watching resumed for %s", filename)
return return
} }
} }
@ -37,14 +37,14 @@ func WatchForUpdates(filename string, done <-chan bool, action func()) {
filename = filepath.Clean(filename) filename = filepath.Clean(filename)
watcher, err := fsnotify.NewWatcher() watcher, err := fsnotify.NewWatcher()
if err != nil { if err != nil {
log.Fatal("failed to create watcher for ", filename, ": ", err) logger.Fatal("failed to create watcher for ", filename, ": ", err)
} }
go func() { go func() {
defer watcher.Close() defer watcher.Close()
for { for {
select { select {
case _ = <-done: case _ = <-done:
log.Printf("Shutting down watcher for: %s", filename) logger.Printf("Shutting down watcher for: %s", filename)
return return
case event := <-watcher.Events: case event := <-watcher.Events:
// On Arch Linux, it appears Chmod events precede Remove events, // On Arch Linux, it appears Chmod events precede Remove events,
@ -53,19 +53,19 @@ func WatchForUpdates(filename string, done <-chan bool, action func()) {
// UserMap.LoadAuthenticatedEmailsFile()) crashes when the file // UserMap.LoadAuthenticatedEmailsFile()) crashes when the file
// can't be opened. // can't be opened.
if event.Op&(fsnotify.Remove|fsnotify.Rename|fsnotify.Chmod) != 0 { if event.Op&(fsnotify.Remove|fsnotify.Rename|fsnotify.Chmod) != 0 {
log.Printf("watching interrupted on event: %s", event) logger.Printf("watching interrupted on event: %s", event)
watcher.Remove(filename) watcher.Remove(filename)
WaitForReplacement(filename, event.Op, watcher) WaitForReplacement(filename, event.Op, watcher)
} }
log.Printf("reloading after event: %s", event) logger.Printf("reloading after event: %s", event)
action() action()
case err = <-watcher.Errors: case err = <-watcher.Errors:
log.Printf("error watching %s: %s", filename, err) logger.Printf("error watching %s: %s", filename, err)
} }
} }
}() }()
if err = watcher.Add(filename); err != nil { if err = watcher.Add(filename); err != nil {
log.Fatal("failed to add ", filename, " to watcher: ", err) logger.Fatal("failed to add ", filename, " to watcher: ", err)
} }
log.Printf("watching %s for updates", filename) logger.Printf("watching %s for updates", filename)
} }

View File

@ -2,11 +2,9 @@
package main package main
import ( import "github.com/pusher/oauth2_proxy/logger"
"log"
)
func WatchForUpdates(filename string, done <-chan bool, action func()) { func WatchForUpdates(filename string, done <-chan bool, action func()) {
log.Printf("file watching not implemented on this platform") logger.Printf("file watching not implemented on this platform")
go func() { <-done }() go func() { <-done }()
} }