93b7d31 · typeable/oauth2-proxy

CHANGELOG.md+15

compare with master

unifiedsplit

@@ -2,6 +2,21 @@

2

3## Changes since v3.2.0

4

5+- [#52](https://github.com/pusher/oauth2_proxy/pull/52) Logging Improvements (@MisterWil)

6+ - Implement flags to configure file logging

7+ - `-logging-filename` Defines the filename to log to

8+ - `-logging-max-size` Defines the maximum

9+ - `-logging-max-age` Defines the maximum age of backups to retain

10+ - `-logging-max-backups` Defines the maximum number of rollover log files to retain

11+ - `-logging-compress` Defines if rollover log files should be compressed

12+ - `-logging-local-time` Defines if logging date and time should be local or UTC

13+ - Implement two new flags to enable or disable specific logging types

14+ - `-standard-logging` Enables or disables standard (not request or auth) logging

15+ - `-auth-logging` Enables or disables auth logging

16+ - Implement two new flags to customize the logging format

17+ - `-standard-logging-format` Sets the format for standard logging

18+ - `-auth-logging-format` Sets the format for auth logging

19+

5- [#111](https://github.com/pusher/oauth2_proxy/pull/111) Add option for telling where to find a login.gov JWT key file (@timothy-spencer)

20- [#111](https://github.com/pusher/oauth2_proxy/pull/111) Add option for telling where to find a login.gov JWT key file (@timothy-spencer)

6

21

7# v3.2.0

22# v3.2.0

Gopkg.lock+9

@@ -190,6 +190,14 @@

190 revision = "836bfd95fecc0f1511dd66bdbf2b5b61ab8b00b6"

191 version = "v1.2.11"

192

193+[[projects]]

194+ digest = "1:11c58e19ff7ce22740423bb933f1ddca3bf575def40d5ac3437ec12871b1648b"

195+ name = "gopkg.in/natefinch/lumberjack.v2"

196+ packages = ["."]

197+ pruneopts = ""

198+ revision = "a96e63847dc3c67d17befa69c303767e2f84e54f"

199+ version = "v2.1"

200+

193[[projects]]

201[[projects]]

194 digest = "1:be4ed0a2b15944dd777a663681a39260ed05f9c4e213017ed2e2255622c8820c"

202 digest = "1:be4ed0a2b15944dd777a663681a39260ed05f9c4e213017ed2e2255622c8820c"

195 name = "gopkg.in/square/go-jose.v2"

203 name = "gopkg.in/square/go-jose.v2"

@@ -222,6 +230,7 @@

222 "google.golang.org/api/admin/directory/v1",

230 "google.golang.org/api/admin/directory/v1",

223 "google.golang.org/api/googleapi",

231 "google.golang.org/api/googleapi",

224 "gopkg.in/fsnotify/fsnotify.v1",

232 "gopkg.in/fsnotify/fsnotify.v1",

233+ "gopkg.in/natefinch/lumberjack.v2",

225 ]

234 ]

226 solver-name = "gps-cdcl"

235 solver-name = "gps-cdcl"

227 solver-version = 1

236 solver-version = 1

Gopkg.toml+4

@@ -38,3 +38,7 @@

38[[constraint]]

39 branch = "master"

40 name = "golang.org/x/crypto"

41+

42+[[constraint]]

43+ name = "gopkg.in/natefinch/lumberjack.v2"

44+ version = "2.1.0"

README.md+93−4

@@ -270,6 +270,8 @@ An example [oauth2_proxy.cfg](contrib/oauth2_proxy.cfg.example) config file is i

270Usage of oauth2_proxy:

271 -acr-values string: optional, used by login.gov (default "http://idmanagement.gov/ns/assurance/loa/1")

272 -approval-prompt string: OAuth approval_prompt (default "force")

273+ -auth-logging: Log authentication attempts (default true)

274+ -auth-logging-format string: Template for authentication log lines (see "Logging Configuration" paragraph below)

273 -authenticated-emails-file string: authenticate against emails via file (one per line)

275 -authenticated-emails-file string: authenticate against emails via file (one per line)

274 -azure-tenant string: go to a tenant-specific or common (tenant-independent) endpoint. (default "common")

276 -azure-tenant string: go to a tenant-specific or common (tenant-independent) endpoint. (default "common")

275 -basic-auth-password string: the password to set when passing the HTTP Basic Auth header

277 -basic-auth-password string: the password to set when passing the HTTP Basic Auth header

@@ -298,6 +300,12 @@ Usage of oauth2_proxy:

298 -htpasswd-file string: additionally authenticate against a htpasswd file. Entries must be created with "htpasswd -s" for SHA encryption

300 -htpasswd-file string: additionally authenticate against a htpasswd file. Entries must be created with "htpasswd -s" for SHA encryption

299 -http-address string: [http://]<addr>:<port> or unix://<path> to listen on for HTTP clients (default "127.0.0.1:4180")

301 -http-address string: [http://]<addr>:<port> or unix://<path> to listen on for HTTP clients (default "127.0.0.1:4180")

300 -https-address string: <addr>:<port> to listen on for HTTPS clients (default ":443")

302 -https-address string: <addr>:<port> to listen on for HTTPS clients (default ":443")

303+ -logging-compress: Should rotated log files be compressed using gzip (default false)

304+ -logging-filename string: File to log requests to, empty for stdout (default to stdout)

305+ -logging-local-time: If the time in log files and backup filenames are local or UTC time (default true)

306+ -logging-max-age int: Maximum number of days to retain old log files (default 7)

307+ -logging-max-backups int: Maximum number of old log files to retain; 0 to disable (default 0)

308+ -logging-max-size int: Maximum size in megabytes of the log file before rotation (default 100)

301 -jwt-key string: private key in PEM format used to sign JWT, so that you can say something like -jwt-key="${OAUTH2_PROXY_JWT_KEY}": required by login.gov

309 -jwt-key string: private key in PEM format used to sign JWT, so that you can say something like -jwt-key="${OAUTH2_PROXY_JWT_KEY}": required by login.gov

302 -jwt-key-file string: path to the private key file in PEM format used to sign the JWT so that you can say something like -jwt-key-file=/etc/ssl/private/jwt_signing_key.pem: required by login.gov

310 -jwt-key-file string: path to the private key file in PEM format used to sign the JWT so that you can say something like -jwt-key-file=/etc/ssl/private/jwt_signing_key.pem: required by login.gov

303 -login-url string: Authentication endpoint

311 -login-url string: Authentication endpoint

@@ -316,7 +324,7 @@ Usage of oauth2_proxy:

316 -redeem-url string: Token redemption endpoint

324 -redeem-url string: Token redemption endpoint

317 -redirect-url string: the OAuth Redirect URL. ie: "https://internalapp.yourcompany.com/oauth2/callback"

325 -redirect-url string: the OAuth Redirect URL. ie: "https://internalapp.yourcompany.com/oauth2/callback"

318 -request-logging: Log requests to stdout (default true)

326 -request-logging: Log requests to stdout (default true)

319− -request-logging-format: Template for request log lines (see "Logging Format" paragraph below)

327+ -request-logging-format: Template for request log lines (see "Logging Configuration" paragraph below)

320 -resource string: The resource that is protected (Azure AD only)

328 -resource string: The resource that is protected (Azure AD only)

321 -scope string: OAuth scope specification

329 -scope string: OAuth scope specification

322 -set-xauthrequest: set X-Auth-Request-User and X-Auth-Request-Email response headers (useful in Nginx auth_request mode)

330 -set-xauthrequest: set X-Auth-Request-User and X-Auth-Request-Email response headers (useful in Nginx auth_request mode)

@@ -327,6 +335,8 @@ Usage of oauth2_proxy:

327 -skip-oidc-discovery: bypass OIDC endpoint discovery. login-url, redeem-url and oidc-jwks-url must be configured in this case

335 -skip-oidc-discovery: bypass OIDC endpoint discovery. login-url, redeem-url and oidc-jwks-url must be configured in this case

328 -skip-provider-button: will skip sign-in-page to directly reach the next step: oauth/start

336 -skip-provider-button: will skip sign-in-page to directly reach the next step: oauth/start

329 -ssl-insecure-skip-verify: skip validation of certificates presented when using HTTPS

337 -ssl-insecure-skip-verify: skip validation of certificates presented when using HTTPS

338+ -standard-logging: Log standard runtime information (default true)

339+ -standard-logging-format string: Template for standard log lines (see "Logging Configuration" paragraph below)

330 -tls-cert string: path to certificate file

340 -tls-cert string: path to certificate file

331 -tls-key string: path to private key file

341 -tls-key string: path to private key file

332 -upstream value: the http url(s) of the upstream endpoint or file:// paths for static files. Routing is based on the path

342 -upstream value: the http url(s) of the upstream endpoint or file:// paths for static files. Routing is based on the path

@@ -457,9 +467,52 @@ following:

457- [rc3.org: Using HMAC to authenticate Web service

467- [rc3.org: Using HMAC to authenticate Web service

458 requests](http://rc3.org/2011/12/02/using-hmac-to-authenticate-web-service-requests/)

468 requests](http://rc3.org/2011/12/02/using-hmac-to-authenticate-web-service-requests/)

459

469

460−## Logging Format

470+## Logging Configuration

461

471

462−By default, OAuth2 Proxy logs requests to stdout in a format similar to Apache Combined Log.

472+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.

473+

474+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`).

475+

476+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`.

477+

478+Each type of logging has their own configurable format and variables. By default these formats are similar to the Apache Combined Log.

479+

480+### Auth Log Format

481+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:

482+

483+```

484+<REMOTE_ADDRESS> - <user@domain.com> [19/Mar/2015:17:20:19 -0400] [<STATUS>] <MESSAGE>

485+```

486+

487+The status block will contain one of the below strings:

488+

489+- `AuthSuccess` If a user has authenticated successfully by any method

490+- `AuthFailure` If the user failed to authenticate explicitly

491+- `AuthError` If there was an unexpected error during authentication

492+

493+If you require a different format than that, you can configure it with the `-auth-logging-format` flag.

494+The default format is configured as follows:

495+

496+```

497+{{.Client}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}}

498+```

499+

500+Available variables for auth logging:

501+

502+| Variable | Example | Description |

503+| --- | --- | --- |

504+| Client | 74.125.224.72 | The client/remote IP address. Will use the X-Real-IP header it if exists. |

505+| Host | domain.com | The value of the Host header. |

506+| Protocol | HTTP/1.0 | The request protocol. |

507+| RequestMethod | GET | The request method. |

508+| Timestamp | 19/Mar/2015:17:20:19 -0400 | The date and time of the logging event. |

509+| UserAgent | - | The full user agent as reported by the requesting client. |

510+| Username | username@email.com | The email or username of the auth request. |

511+| Status | AuthSuccess | The status of the auth request. See above for details. |

512+| Message | Authenticated via OAuth2 | The details of the auth attempt. |

513+

514+### Request Log Format

515+HTTP request logs will output by default in the below format:

463

516

464```

517```

465<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>

518<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>

@@ -472,7 +525,43 @@ The default format is configured as follows:

472{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}

525{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}

473```

526```

474

527

475−[See `logMessageData` in `logging_handler.go`](./logging_handler.go) for all available variables.

528+Available variables for request logging:

529+

530+| Variable | Example | Description |

531+| --- | --- | --- |

532+| Client | 74.125.224.72 | The client/remote IP address. Will use the X-Real-IP header it if exists. |

533+| Host | domain.com | The value of the Host header. |

534+| Protocol | HTTP/1.0 | The request protocol. |

535+| RequestDuration | 0.001 | The time in seconds that a request took to process. |

536+| RequestMethod | GET | The request method. |

537+| RequestURI | "/oauth2/auth" | The URI path of the request. |

538+| ResponseSize | 12 | The size in bytes of the response. |

539+| StatusCode | 200 | The HTTP status code of the response. |

540+| Timestamp | 19/Mar/2015:17:20:19 -0400 | The date and time of the logging event. |

541+| Upstream | - | The upstream data of the HTTP request. |

542+| UserAgent | - | The full user agent as reported by the requesting client. |

543+| Username | username@email.com | The email or username of the auth request. |

544+

545+### Standard Log Format

546+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:

547+

548+```

549+[19/Mar/2015:17:20:19 -0400] [main.go:40] <MESSAGE>

550+```

551+

552+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:

553+

554+```

555+[{{.Timestamp}}] [{{.File}}] {{.Message}}

556+```

557+

558+Available variables for standard logging:

559+

560+| Variable | Example | Description |

561+| --- | --- | --- |

562+| Timestamp | 19/Mar/2015:17:20:19 -0400 | The date and time of the logging event. |

563+| File | main.go:40 | The file and line number of the logging statement. |

564+| Message | HTTP: listening on 127.0.0.1:4180 | The details of the log statement. |

476

565

477## Adding a new Provider

566## Adding a new Provider

478

567

api/api.go+5−5

@@ -4,22 +4,22 @@ import (

4 "encoding/json"

5 "fmt"

6 "io/ioutil"

7− "log"

8 "net/http"

7 "net/http"

9

8

10 "github.com/bitly/go-simplejson"

9 "github.com/bitly/go-simplejson"

10+ "github.com/pusher/oauth2_proxy/logger"

11)

12

13// Request parses the request body into a simplejson.Json object

14func Request(req *http.Request) (*simplejson.Json, error) {

15 resp, err := http.DefaultClient.Do(req)

16 if err != nil {

17− log.Printf("%s %s %s", req.Method, req.URL, err)

17+ logger.Printf("%s %s %s", req.Method, req.URL, err)

18 return nil, err

19 }

20 body, err := ioutil.ReadAll(resp.Body)

21 resp.Body.Close()

22− log.Printf("%d %s %s %s", resp.StatusCode, req.Method, req.URL, body)

22+ logger.Printf("%d %s %s %s", resp.StatusCode, req.Method, req.URL, body)

23 if err != nil {

24 return nil, err

25 }

@@ -37,12 +37,12 @@ func Request(req *http.Request) (*simplejson.Json, error) {

37func RequestJSON(req *http.Request, v interface{}) error {

38 resp, err := http.DefaultClient.Do(req)

39 if err != nil {

40− log.Printf("%s %s %s", req.Method, req.URL, err)

40+ logger.Printf("%s %s %s", req.Method, req.URL, err)

41 return err

42 }

43 body, err := ioutil.ReadAll(resp.Body)

44 resp.Body.Close()

45− log.Printf("%d %s %s %s", resp.StatusCode, req.Method, req.URL, body)

45+ logger.Printf("%d %s %s %s", resp.StatusCode, req.Method, req.URL, body)

46 if err != nil {

47 return err

48 }

contrib/oauth2_proxy.cfg.example+12−2

@@ -18,8 +18,18 @@

18# "http://127.0.0.1:8080/"

19# ]

20

21−## Log requests to stdout

21+## Logging configuration

22+#logging_filename = ""

23+#logging_max_size = 100

24+#logging_max_age = 7

25+#logging_local_time = true

26+#logging_compress = false

27+#standard_logging = true

28+#standard_logging_format = "[{{.Timestamp}}] [{{.File}}] {{.Message}}"

22−# request_logging = true

29+#request_logging = true

30+#request_logging_format = "{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}"

31+#auth_logging = true

32+#auth_logging_format = "{{.Client}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}}"

23

33

24## pass HTTP Basic Auth, X-Forwarded-User and X-Forwarded-Email information to upstream

34## pass HTTP Basic Auth, X-Forwarded-User and X-Forwarded-Email information to upstream

25# pass_basic_auth = true

35# pass_basic_auth = true

htpasswd.go+2−2

@@ -5,9 +5,9 @@ import (

5 "encoding/base64"

6 "encoding/csv"

7 "io"

8− "log"

9 "os"

8 "os"

10

9

10+ "github.com/pusher/oauth2_proxy/logger"

11 "golang.org/x/crypto/bcrypt"

12)

13

@@ -67,6 +67,6 @@ func (h *HtpasswdFile) Validate(user string, password string) bool {

67 return bcrypt.CompareHashAndPassword([]byte(realPassword), []byte(password)) == nil

68 }

69

70− log.Printf("Invalid htpasswd entry for %s. Must be a SHA or bcrypt entry.", user)

70+ logger.Printf("Invalid htpasswd entry for %s. Must be a SHA or bcrypt entry.", user)

71 return false

72}

http.go+11−10

@@ -2,11 +2,12 @@ package main

2

3import (

4 "crypto/tls"

5− "log"

6 "net"

5 "net"

7 "net/http"

6 "net/http"

8 "strings"

7 "strings"

9 "time"

8 "time"

9+

10+ "github.com/pusher/oauth2_proxy/logger"

10)

11)

11

12

12// Server represents an HTTP server

13// Server represents an HTTP server

@@ -86,17 +87,17 @@ func (s *Server) ServeHTTP() {

86

87

87 listener, err := net.Listen(networkType, listenAddr)

88 listener, err := net.Listen(networkType, listenAddr)

88 if err != nil {

89 if err != nil {

89− log.Fatalf("FATAL: listen (%s, %s) failed - %s", networkType, listenAddr, err)

90+ logger.Fatalf("FATAL: listen (%s, %s) failed - %s", networkType, listenAddr, err)

90 }

91 }

91− log.Printf("HTTP: listening on %s", listenAddr)

92+ logger.Printf("HTTP: listening on %s", listenAddr)

92

93

93 server := &http.Server{Handler: s.Handler}

94 server := &http.Server{Handler: s.Handler}

94 err = server.Serve(listener)

95 err = server.Serve(listener)

95 if err != nil && !strings.Contains(err.Error(), "use of closed network connection") {

96 if err != nil && !strings.Contains(err.Error(), "use of closed network connection") {

96− log.Printf("ERROR: http.Serve() - %s", err)

97+ logger.Printf("ERROR: http.Serve() - %s", err)

97 }

98 }

98

99

99− log.Printf("HTTP: closing %s", listener.Addr())

100+ logger.Printf("HTTP: closing %s", listener.Addr())

100}

101}

101

102

102// ServeHTTPS constructs a net.Listener and starts handling HTTPS requests

103// ServeHTTPS constructs a net.Listener and starts handling HTTPS requests

@@ -114,24 +115,24 @@ func (s *Server) ServeHTTPS() {

114 config.Certificates = make([]tls.Certificate, 1)

115 config.Certificates = make([]tls.Certificate, 1)

115 config.Certificates[0], err = tls.LoadX509KeyPair(s.Opts.TLSCertFile, s.Opts.TLSKeyFile)

116 config.Certificates[0], err = tls.LoadX509KeyPair(s.Opts.TLSCertFile, s.Opts.TLSKeyFile)

116 if err != nil {

117 if err != nil {

117− log.Fatalf("FATAL: loading tls config (%s, %s) failed - %s", s.Opts.TLSCertFile, s.Opts.TLSKeyFile, err)

118+ logger.Fatalf("FATAL: loading tls config (%s, %s) failed - %s", s.Opts.TLSCertFile, s.Opts.TLSKeyFile, err)

118 }

119 }

119

120

120 ln, err := net.Listen("tcp", addr)

121 ln, err := net.Listen("tcp", addr)

121 if err != nil {

122 if err != nil {

122− log.Fatalf("FATAL: listen (%s) failed - %s", addr, err)

123+ logger.Fatalf("FATAL: listen (%s) failed - %s", addr, err)

123 }

124 }

124− log.Printf("HTTPS: listening on %s", ln.Addr())

125+ logger.Printf("HTTPS: listening on %s", ln.Addr())

125

126

126 tlsListener := tls.NewListener(tcpKeepAliveListener{ln.(*net.TCPListener)}, config)

127 tlsListener := tls.NewListener(tcpKeepAliveListener{ln.(*net.TCPListener)}, config)

127 srv := &http.Server{Handler: s.Handler}

128 srv := &http.Server{Handler: s.Handler}

128 err = srv.Serve(tlsListener)

129 err = srv.Serve(tlsListener)

129

130

130 if err != nil && !strings.Contains(err.Error(), "use of closed network connection") {

131 if err != nil && !strings.Contains(err.Error(), "use of closed network connection") {

131− log.Printf("ERROR: https.Serve() - %s", err)

132+ logger.Printf("ERROR: https.Serve() - %s", err)

132 }

133 }

133

134

134− log.Printf("HTTPS: closing %s", tlsListener.Addr())

135+ logger.Printf("HTTPS: closing %s", tlsListener.Addr())

135}

136}

136

137

137// tcpKeepAliveListener sets TCP keep-alive timeouts on accepted

138// tcpKeepAliveListener sets TCP keep-alive timeouts on accepted

logger/logger.gonew file+452

@@ -0,0 +1,452 @@

1+package logger

2+

3+import (

4+ "fmt"

5+ "io"

6+ "net"

7+ "net/http"

8+ "net/url"

9+ "os"

10+ "runtime"

11+ "sync"

12+ "text/template"

13+ "time"

14+)

15+

16+// AuthStatus defines the different types of auth logging that occur

17+type AuthStatus string

18+

19+const (

20+ // DefaultStandardLoggingFormat defines the default standard log format

21+ DefaultStandardLoggingFormat = "[{{.Timestamp}}] [{{.File}}] {{.Message}}"

22+ // DefaultAuthLoggingFormat defines the default auth log format

23+ DefaultAuthLoggingFormat = "{{.Client}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}}"

24+ // DefaultRequestLoggingFormat defines the default request log format

25+ DefaultRequestLoggingFormat = "{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}"

26+

27+ // AuthSuccess indicates that an auth attempt has succeeded explicitly

28+ AuthSuccess AuthStatus = "AuthSuccess"

29+ // AuthFailure indicates that an auth attempt has failed explicitly

30+ AuthFailure AuthStatus = "AuthFailure"

31+ // AuthError indicates that an auth attempt has failed due to an error

32+ AuthError AuthStatus = "AuthError"

33+

34+ // Llongfile flag to log full file name and line number: /a/b/c/d.go:23

35+ Llongfile = 1 << iota

36+ // Lshortfile flag to log final file name element and line number: d.go:23. overrides Llongfile

37+ Lshortfile

38+ // LUTC flag to log UTC datetime rather than the local time zone

39+ LUTC

40+ // LstdFlags flag for initial values for the logger

41+ LstdFlags = Lshortfile

42+)

43+

44+// These are the containers for all values that are available as variables in the logging formats.

45+// All values are pre-formatted strings so it is easy to use them in the format string.

46+type stdLogMessageData struct {

47+ Timestamp,

48+ File,

49+ Message string

50+}

51+

52+type authLogMessageData struct {

53+ Client,

54+ Host,

55+ Protocol,

56+ RequestMethod,

57+ Timestamp,

58+ UserAgent,

59+ Username,

60+ Status,

61+ Message string

62+}

63+

64+type reqLogMessageData struct {

65+ Client,

66+ Host,

67+ Protocol,

68+ RequestDuration,

69+ RequestMethod,

70+ RequestURI,

71+ ResponseSize,

72+ StatusCode,

73+ Timestamp,

74+ Upstream,

75+ UserAgent,

76+ Username string

77+}

78+

79+// A Logger represents an active logging object that generates lines of

80+// output to an io.Writer passed through a formatter. Each logging

81+// operation makes a single call to the Writer's Write method. A Logger

82+// can be used simultaneously from multiple goroutines; it guarantees to

83+// serialize access to the Writer.

84+type Logger struct {

85+ mu sync.Mutex

86+ flag int

87+ writer io.Writer

88+ stdEnabled bool

89+ authEnabled bool

90+ reqEnabled bool

91+ stdLogTemplate *template.Template

92+ authTemplate *template.Template

93+ reqTemplate *template.Template

94+}

95+

96+// New creates a new Standarderr Logger.

97+func New(flag int) *Logger {

98+ return &Logger{

99+ writer: os.Stderr,

100+ flag: flag,

101+ stdEnabled: true,

102+ authEnabled: true,

103+ reqEnabled: true,

104+ stdLogTemplate: template.Must(template.New("std-log").Parse(DefaultStandardLoggingFormat)),

105+ authTemplate: template.Must(template.New("auth-log").Parse(DefaultAuthLoggingFormat)),

106+ reqTemplate: template.Must(template.New("req-log").Parse(DefaultRequestLoggingFormat)),

107+ }

108+}

109+

110+var std = New(LstdFlags)

111+

112+// Output a standard log template with a simple message.

113+// Write a final newline at the end of every message.

114+func (l *Logger) Output(calldepth int, message string) {

115+ if !l.stdEnabled {

116+ return

117+ }

118+

119+ now := time.Now()

120+ file := "???:0"

121+

122+ if l.flag&(Lshortfile|Llongfile) != 0 {

123+ file = l.GetFileLineString(calldepth + 1)

124+ }

125+

126+ l.mu.Lock()

127+ defer l.mu.Unlock()

128+

129+ l.stdLogTemplate.Execute(l.writer, stdLogMessageData{

130+ Timestamp: FormatTimestamp(now),

131+ File: file,

132+ Message: message,

133+ })

134+

135+ l.writer.Write([]byte("\n"))

136+}

137+

138+// PrintAuth writes auth info to the logger. Requires an http.Request to

139+// log request details. Remaining arguments are handled in the manner of

140+// fmt.Sprintf. Writes a final newline to the end of every message.

141+func (l *Logger) PrintAuth(username string, req *http.Request, status AuthStatus, format string, a ...interface{}) {

142+ if !l.authEnabled {

143+ return

144+ }

145+

146+ now := time.Now()

147+

148+ if username == "" {

149+ username = "-"

150+ }

151+

152+ client := GetClient(req)

153+

154+ l.mu.Lock()

155+ defer l.mu.Unlock()

156+

157+ l.authTemplate.Execute(l.writer, authLogMessageData{

158+ Client: client,

159+ Host: req.Host,

160+ Protocol: req.Proto,

161+ RequestMethod: req.Method,

162+ Timestamp: FormatTimestamp(now),

163+ UserAgent: fmt.Sprintf("%q", req.UserAgent()),

164+ Username: username,

165+ Status: fmt.Sprintf("%s", status),

166+ Message: fmt.Sprintf(format, a...),

167+ })

168+

169+ l.writer.Write([]byte("\n"))

170+}

171+

172+// PrintReq writes request details to the Logger using the http.Request,

173+// url, and timestamp of the request. Writes a final newline to the end

174+// of every message.

175+func (l *Logger) PrintReq(username, upstream string, req *http.Request, url url.URL, ts time.Time, status int, size int) {

176+ if !l.reqEnabled {

177+ return

178+ }

179+

180+ duration := float64(time.Now().Sub(ts)) / float64(time.Second)

181+

182+ if username == "" {

183+ username = "-"

184+ }

185+

186+ if upstream == "" {

187+ upstream = "-"

188+ }

189+

190+ if url.User != nil && username == "-" {

191+ if name := url.User.Username(); name != "" {

192+ username = name

193+ }

194+ }

195+

196+ client := GetClient(req)

197+

198+ l.mu.Lock()

199+ defer l.mu.Unlock()

200+

201+ l.reqTemplate.Execute(l.writer, reqLogMessageData{

202+ Client: client,

203+ Host: req.Host,

204+ Protocol: req.Proto,

205+ RequestDuration: fmt.Sprintf("%0.3f", duration),

206+ RequestMethod: req.Method,

207+ RequestURI: fmt.Sprintf("%q", url.RequestURI()),

208+ ResponseSize: fmt.Sprintf("%d", size),

209+ StatusCode: fmt.Sprintf("%d", status),

210+ Timestamp: FormatTimestamp(ts),

211+ Upstream: upstream,

212+ UserAgent: fmt.Sprintf("%q", req.UserAgent()),

213+ Username: username,

214+ })

215+

216+ l.writer.Write([]byte("\n"))

217+}

218+

219+// GetFileLineString will find the caller file and line number

220+// taking in to account the calldepth to iterate up the stack

221+// to find the non-logging call location.

222+func (l *Logger) GetFileLineString(calldepth int) string {

223+ var file string

224+ var line int

225+ var ok bool

226+

227+ _, file, line, ok = runtime.Caller(calldepth)

228+ if !ok {

229+ file = "???"

230+ line = 0

231+ }

232+

233+ if l.flag&Lshortfile != 0 {

234+ short := file

235+ for i := len(file) - 1; i > 0; i-- {

236+ if file[i] == '/' {

237+ short = file[i+1:]

238+ break

239+ }

240+ }

241+ file = short

242+ }

243+

244+ return fmt.Sprintf("%s:%d", file, line)

245+}

246+

247+// GetClient parses an HTTP request for the client/remote IP address.

248+func GetClient(req *http.Request) string {

249+ client := req.Header.Get("X-Real-IP")

250+ if client == "" {

251+ client = req.RemoteAddr

252+ }

253+

254+ if c, _, err := net.SplitHostPort(client); err == nil {

255+ client = c

256+ }

257+

258+ return client

259+}

260+

261+// FormatTimestamp returns a formatted timestamp.

262+func (l *Logger) FormatTimestamp(ts time.Time) string {

263+ if l.flag&LUTC != 0 {

264+ ts = ts.UTC()

265+ }

266+

267+ return ts.Format("2006/01/02 15:04:05")

268+}

269+

270+// Flags returns the output flags for the logger.

271+func (l *Logger) Flags() int {

272+ l.mu.Lock()

273+ defer l.mu.Unlock()

274+ return l.flag

275+}

276+

277+// SetFlags sets the output flags for the logger.

278+func (l *Logger) SetFlags(flag int) {

279+ l.mu.Lock()

280+ defer l.mu.Unlock()

281+ l.flag = flag

282+}

283+

284+// SetStandardEnabled enables or disables standard logging.

285+func (l *Logger) SetStandardEnabled(e bool) {

286+ l.mu.Lock()

287+ defer l.mu.Unlock()

288+ l.stdEnabled = e

289+}

290+

291+// SetAuthEnabled enables or disables auth logging.

292+func (l *Logger) SetAuthEnabled(e bool) {

293+ l.mu.Lock()

294+ defer l.mu.Unlock()

295+ l.authEnabled = e

296+}

297+

298+// SetReqEnabled enabled or disables request logging.

299+func (l *Logger) SetReqEnabled(e bool) {

300+ l.mu.Lock()

301+ defer l.mu.Unlock()

302+ l.reqEnabled = e

303+}

304+

305+// SetStandardTemplate sets the template for standard logging.

306+func (l *Logger) SetStandardTemplate(t string) {

307+ l.mu.Lock()

308+ defer l.mu.Unlock()

309+ l.stdLogTemplate = template.Must(template.New("std-log").Parse(t))

310+}

311+

312+// SetAuthTemplate sets the template for auth logging.

313+func (l *Logger) SetAuthTemplate(t string) {

314+ l.mu.Lock()

315+ defer l.mu.Unlock()

316+ l.authTemplate = template.Must(template.New("auth-log").Parse(t))

317+}

318+

319+// SetReqTemplate sets the template for request logging.

320+func (l *Logger) SetReqTemplate(t string) {

321+ l.mu.Lock()

322+ defer l.mu.Unlock()

323+ l.reqTemplate = template.Must(template.New("req-log").Parse(t))

324+}

325+

326+// These functions utilize the standard logger.

327+

328+// FormatTimestamp returns a formatted timestamp for the standard logger.

329+func FormatTimestamp(ts time.Time) string {

330+ return std.FormatTimestamp(ts)

331+}

332+

333+// Flags returns the output flags for the standard logger.

334+func Flags() int {

335+ return std.Flags()

336+}

337+

338+// SetFlags sets the output flags for the standard logger.

339+func SetFlags(flag int) {

340+ std.SetFlags(flag)

341+}

342+

343+// SetOutput sets the output destination for the standard logger.

344+func SetOutput(w io.Writer) {

345+ std.mu.Lock()

346+ defer std.mu.Unlock()

347+ std.writer = w

348+}

349+

350+// SetStandardEnabled enables or disables standard logging for the

351+// standard logger.

352+func SetStandardEnabled(e bool) {

353+ std.SetStandardEnabled(e)

354+}

355+

356+// SetAuthEnabled enables or disables auth logging for the standard

357+// logger.

358+func SetAuthEnabled(e bool) {

359+ std.SetAuthEnabled(e)

360+}

361+

362+// SetReqEnabled enables or disables request logging for the

363+// standard logger.

364+func SetReqEnabled(e bool) {

365+ std.SetReqEnabled(e)

366+}

367+

368+// SetStandardTemplate sets the template for standard logging for

369+// the standard logger.

370+func SetStandardTemplate(t string) {

371+ std.SetStandardTemplate(t)

372+}

373+

374+// SetAuthTemplate sets the template for auth logging for the

375+// standard logger.

376+func SetAuthTemplate(t string) {

377+ std.SetAuthTemplate(t)

378+}

379+

380+// SetReqTemplate sets the template for request logging for the

381+// standard logger.

382+func SetReqTemplate(t string) {

383+ std.SetReqTemplate(t)

384+}

385+

386+// Print calls Output to print to the standard logger.

387+// Arguments are handled in the manner of fmt.Print.

388+func Print(v ...interface{}) {

389+ std.Output(2, fmt.Sprint(v...))

390+}

391+

392+// Printf calls Output to print to the standard logger.

393+// Arguments are handled in the manner of fmt.Printf.

394+func Printf(format string, v ...interface{}) {

395+ std.Output(2, fmt.Sprintf(format, v...))

396+}

397+

398+// Println calls Output to print to the standard logger.

399+// Arguments are handled in the manner of fmt.Println.

400+func Println(v ...interface{}) {

401+ std.Output(2, fmt.Sprintln(v...))

402+}

403+

404+// Fatal is equivalent to Print() followed by a call to os.Exit(1).

405+func Fatal(v ...interface{}) {

406+ std.Output(2, fmt.Sprint(v...))

407+ os.Exit(1)

408+}

409+

410+// Fatalf is equivalent to Printf() followed by a call to os.Exit(1).

411+func Fatalf(format string, v ...interface{}) {

412+ std.Output(2, fmt.Sprintf(format, v...))

413+ os.Exit(1)

414+}

415+

416+// Fatalln is equivalent to Println() followed by a call to os.Exit(1).

417+func Fatalln(v ...interface{}) {

418+ std.Output(2, fmt.Sprintln(v...))

419+ os.Exit(1)

420+}

421+

422+// Panic is equivalent to Print() followed by a call to panic().

423+func Panic(v ...interface{}) {

424+ s := fmt.Sprint(v...)

425+ std.Output(2, s)

426+ panic(s)

427+}

428+

429+// Panicf is equivalent to Printf() followed by a call to panic().

430+func Panicf(format string, v ...interface{}) {

431+ s := fmt.Sprintf(format, v...)

432+ std.Output(2, s)

433+ panic(s)

434+}

435+

436+// Panicln is equivalent to Println() followed by a call to panic().

437+func Panicln(v ...interface{}) {

438+ s := fmt.Sprintln(v...)

439+ std.Output(2, s)

440+ panic(s)

441+}

442+

443+// PrintAuthf writes authentication details to the standard logger.

444+// Arguments are handled in the manner of fmt.Printf.

445+func PrintAuthf(username string, req *http.Request, status AuthStatus, format string, a ...interface{}) {

446+ std.PrintAuth(username, req, status, format, a...)

447+}

448+

449+// PrintReq writes request details to the standard logger.

450+func PrintReq(username, upstream string, req *http.Request, url url.URL, ts time.Time, status int, size int) {

451+ std.PrintReq(username, upstream, req, url, ts, status, size)

452+}

logging_handler.go+7−84

@@ -6,17 +6,11 @@ package main

6import (

7 "bufio"

8 "errors"

9− "fmt"

10− "io"

11 "net"

9 "net"

12 "net/http"

10 "net/http"

13− "net/url"

14− "text/template"

15 "time"

11 "time"

16−)

17

12

18−const (

13+ "github.com/pusher/oauth2_proxy/logger"

19− defaultRequestLoggingFormat = "{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}"

20)

14)

21

15

22// responseLogger is wrapper of http.ResponseWriter that keeps track of its HTTP status

16// responseLogger is wrapper of http.ResponseWriter that keeps track of its HTTP status

@@ -92,93 +86,22 @@ func (l *responseLogger) Flush() {

92 }

86 }

93}

87}

94

88

95−// logMessageData is the container for all values that are available as variables in the request logging format.

96−// All values are pre-formatted strings so it is easy to use them in the format string.

97−type logMessageData struct {

98− Client,

99− Host,

100− Protocol,

101− RequestDuration,

102− RequestMethod,

103− RequestURI,

104− ResponseSize,

105− StatusCode,

106− Timestamp,

107− Upstream,

108− UserAgent,

109− Username string

110−}

111−

112// loggingHandler is the http.Handler implementation for LoggingHandlerTo and its friends

89// loggingHandler is the http.Handler implementation for LoggingHandlerTo and its friends

113type loggingHandler struct {

90type loggingHandler struct {

114− writer io.Writer

115− handler http.Handler

91+ handler http.Handler

116− enabled bool

117− logTemplate *template.Template

118}

92}

119

93

120// LoggingHandler provides an http.Handler which logs requests to the HTTP server

94// LoggingHandler provides an http.Handler which logs requests to the HTTP server

121−func LoggingHandler(out io.Writer, h http.Handler, v bool, requestLoggingTpl string) http.Handler {

95+func LoggingHandler(h http.Handler) http.Handler {

122 return loggingHandler{

96 return loggingHandler{

123− writer: out,

124− handler: h,

97+ handler: h,

125− enabled: v,

126− logTemplate: template.Must(template.New("request-log").Parse(requestLoggingTpl)),

127 }

98 }

128}

99}

129

100

130func (h loggingHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) {

101func (h loggingHandler) ServeHTTP(w http.ResponseWriter, req *http.Request) {

131 t := time.Now()

102 t := time.Now()

132 url := *req.URL

103 url := *req.URL

133− logger := &responseLogger{w: w}

104+ responseLogger := &responseLogger{w: w}

134− h.handler.ServeHTTP(logger, req)

105+ h.handler.ServeHTTP(responseLogger, req)

135− if !h.enabled {

106+ logger.PrintReq(responseLogger.authInfo, responseLogger.upstream, req, url, t, responseLogger.Status(), responseLogger.Size())

136− return

137− }

138− h.writeLogLine(logger.authInfo, logger.upstream, req, url, t, logger.Status(), logger.Size())

139−}

140−

141−// Log entry for req similar to Apache Common Log Format.

142−// ts is the timestamp with which the entry should be logged.

143−// status, size are used to provide the response HTTP status and size.

144−func (h loggingHandler) writeLogLine(username, upstream string, req *http.Request, url url.URL, ts time.Time, status int, size int) {

145− if username == "" {

146− username = "-"

147− }

148− if upstream == "" {

149− upstream = "-"

150− }

151− if url.User != nil && username == "-" {

152− if name := url.User.Username(); name != "" {

153− username = name

154− }

155− }

156−

157− client := req.Header.Get("X-Real-IP")

158− if client == "" {

159− client = req.RemoteAddr

160− }

161−

162− if c, _, err := net.SplitHostPort(client); err == nil {

163− client = c

164− }

165−

166− duration := float64(time.Now().Sub(ts)) / float64(time.Second)

167−

168− h.logTemplate.Execute(h.writer, logMessageData{

169− Client: client,

170− Host: req.Host,

171− Protocol: req.Proto,

172− RequestDuration: fmt.Sprintf("%0.3f", duration),

173− RequestMethod: req.Method,

174− RequestURI: fmt.Sprintf("%q", url.RequestURI()),

175− ResponseSize: fmt.Sprintf("%d", size),

176− StatusCode: fmt.Sprintf("%d", status),

177− Timestamp: ts.Format("02/Jan/2006:15:04:05 -0700"),

178− Upstream: upstream,

179− UserAgent: fmt.Sprintf("%q", req.UserAgent()),

180− Username: username,

181− })

182−

183− h.writer.Write([]byte("\n"))

184}

107}

logging_handler_test.go+6−2

@@ -8,6 +8,8 @@ import (

8 "strings"

9 "testing"

10 "time"

11+

12+ "github.com/pusher/oauth2_proxy/logger"

11)

13)

12

14

13func TestLoggingHandler_ServeHTTP(t *testing.T) {

15func TestLoggingHandler_ServeHTTP(t *testing.T) {

@@ -17,7 +19,7 @@ func TestLoggingHandler_ServeHTTP(t *testing.T) {

17 Format,

19 Format,

18 ExpectedLogMessage string

20 ExpectedLogMessage string

19 }{

21 }{

20− {defaultRequestLoggingFormat, fmt.Sprintf("127.0.0.1 - - [%s] test-server GET - \"/foo/bar\" HTTP/1.1 \"\" 200 4 0", ts.Format("02/Jan/2006:15:04:05 -0700"))},

22+ {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))},

21 {"{{.RequestMethod}}", "GET\n"},

23 {"{{.RequestMethod}}", "GET\n"},

22 }

24 }

23

25

@@ -32,7 +34,9 @@ func TestLoggingHandler_ServeHTTP(t *testing.T) {

32 w.Write([]byte("test"))

34 w.Write([]byte("test"))

33 }

35 }

34

36

37+ logger.SetOutput(buf)

38+ logger.SetReqTemplate(test.Format)

35− h := LoggingHandler(buf, http.HandlerFunc(handler), true, test.Format)

39+ h := LoggingHandler(http.HandlerFunc(handler))

36

40

37 r, _ := http.NewRequest("GET", "/foo/bar", nil)

41 r, _ := http.NewRequest("GET", "/foo/bar", nil)

38 r.RemoteAddr = "127.0.0.1"

42 r.RemoteAddr = "127.0.0.1"

main.go+24−10

@@ -3,7 +3,6 @@ package main

3import (

4 "flag"

5 "fmt"

6− "log"

7 "math/rand"

6 "math/rand"

8 "net/http"

7 "net/http"

9 "os"

8 "os"

@@ -13,10 +12,11 @@ import (

13

12

14 "github.com/BurntSushi/toml"

13 "github.com/BurntSushi/toml"

15 options "github.com/mreiferson/go-options"

14 options "github.com/mreiferson/go-options"

15+ "github.com/pusher/oauth2_proxy/logger"

16)

17

18func main() {

19− log.SetFlags(log.Ldate | log.Ltime | log.Lshortfile)

19+ logger.SetFlags(logger.Lshortfile)

20 flagSet := flag.NewFlagSet("oauth2_proxy", flag.ExitOnError)

21

22 emailDomains := StringArray{}

@@ -75,8 +75,21 @@ func main() {

75 flagSet.Bool("cookie-secure", true, "set secure (HTTPS) cookie flag")

76 flagSet.Bool("cookie-httponly", true, "set HttpOnly cookie flag")

77

78− flagSet.Bool("request-logging", true, "Log requests to stdout")

78+ flagSet.String("logging-filename", "", "File to log requests to, empty for stdout")

79− flagSet.String("request-logging-format", defaultRequestLoggingFormat, "Template for log lines")

79+ flagSet.Int("logging-max-size", 100, "Maximum size in megabytes of the log file before rotation")

80+ flagSet.Int("logging-max-age", 7, "Maximum number of days to retain old log files")

81+ flagSet.Int("logging-max-backups", 0, "Maximum number of old log files to retain; 0 to disable")

82+ flagSet.Bool("logging-local-time", true, "If the time in log files and backup filenames are local or UTC time")

83+ flagSet.Bool("logging-compress", false, "Should rotated log files be compressed using gzip")

84+

85+ flagSet.Bool("standard-logging", true, "Log standard runtime information")

86+ flagSet.String("standard-logging-format", logger.DefaultStandardLoggingFormat, "Template for standard log lines")

87+

88+ flagSet.Bool("request-logging", true, "Log HTTP requests")

89+ flagSet.String("request-logging-format", logger.DefaultRequestLoggingFormat, "Template for HTTP request log lines")

90+

91+ flagSet.Bool("auth-logging", true, "Log authentication attempts")

92+ flagSet.String("auth-logging-format", logger.DefaultAuthLoggingFormat, "Template for authentication log lines")

80

93

81 flagSet.String("provider", "google", "OAuth provider")

94 flagSet.String("provider", "google", "OAuth provider")

82 flagSet.String("oidc-issuer-url", "", "OpenID Connect issuer URL (ie: https://accounts.google.com)")

95 flagSet.String("oidc-issuer-url", "", "OpenID Connect issuer URL (ie: https://accounts.google.com)")

@@ -110,7 +123,7 @@ func main() {

110 if *config != "" {

123 if *config != "" {

111 _, err := toml.DecodeFile(*config, &cfg)

124 _, err := toml.DecodeFile(*config, &cfg)

112 if err != nil {

125 if err != nil {

113− log.Fatalf("ERROR: failed to load config file %s - %s", *config, err)

126+ logger.Fatalf("ERROR: failed to load config file %s - %s", *config, err)

114 }

127 }

115 }

128 }

116 cfg.LoadEnvForStruct(opts)

129 cfg.LoadEnvForStruct(opts)

@@ -118,9 +131,10 @@ func main() {

118

131

119 err := opts.Validate()

132 err := opts.Validate()

120 if err != nil {

133 if err != nil {

121− log.Printf("%s", err)

134+ logger.Printf("%s", err)

122 os.Exit(1)

135 os.Exit(1)

123 }

136 }

137+

124 validator := NewValidator(opts.EmailDomains, opts.AuthenticatedEmailsFile)

138 validator := NewValidator(opts.EmailDomains, opts.AuthenticatedEmailsFile)

125 oauthproxy := NewOAuthProxy(opts, validator)

139 oauthproxy := NewOAuthProxy(opts, validator)

126

140

@@ -133,11 +147,11 @@ func main() {

133 }

147 }

134

148

135 if opts.HtpasswdFile != "" {

149 if opts.HtpasswdFile != "" {

136− log.Printf("using htpasswd file %s", opts.HtpasswdFile)

150+ logger.Printf("using htpasswd file %s", opts.HtpasswdFile)

137 oauthproxy.HtpasswdFile, err = NewHtpasswdFromFile(opts.HtpasswdFile)

151 oauthproxy.HtpasswdFile, err = NewHtpasswdFromFile(opts.HtpasswdFile)

138 oauthproxy.DisplayHtpasswdForm = opts.DisplayHtpasswdForm

152 oauthproxy.DisplayHtpasswdForm = opts.DisplayHtpasswdForm

139 if err != nil {

153 if err != nil {

140− log.Fatalf("FATAL: unable to open %s %s", opts.HtpasswdFile, err)

154+ logger.Fatalf("FATAL: unable to open %s %s", opts.HtpasswdFile, err)

141 }

155 }

142 }

156 }

143

157

@@ -145,9 +159,9 @@ func main() {

145

159

146 var handler http.Handler

160 var handler http.Handler

147 if opts.GCPHealthChecks {

161 if opts.GCPHealthChecks {

148− handler = gcpHealthcheck(LoggingHandler(os.Stdout, oauthproxy, opts.RequestLogging, opts.RequestLoggingFormat))

162+ handler = gcpHealthcheck(LoggingHandler(oauthproxy))

149 } else {

163 } else {

150− handler = LoggingHandler(os.Stdout, oauthproxy, opts.RequestLogging, opts.RequestLoggingFormat)

164+ handler = LoggingHandler(oauthproxy)

151 }

165 }

152 s := &Server{

166 s := &Server{

153 Handler: handler,

167 Handler: handler,

oauthproxy.go+33−25

@@ -5,7 +5,6 @@ import (

5 "errors"

6 "fmt"

7 "html/template"

8− "log"

9 "net"

8 "net"

10 "net/http"

9 "net/http"

11 "net/http/httputil"

10 "net/http/httputil"

@@ -16,6 +15,7 @@ import (

16

15

17 "github.com/mbland/hmacauth"

16 "github.com/mbland/hmacauth"

18 "github.com/pusher/oauth2_proxy/cookie"

17 "github.com/pusher/oauth2_proxy/cookie"

18+ "github.com/pusher/oauth2_proxy/logger"

19 "github.com/pusher/oauth2_proxy/providers"

20 "github.com/yhat/wsutil"

21)

@@ -185,7 +185,7 @@ func NewOAuthProxy(opts *Options, validator func(string) bool) *OAuthProxy {

185 path := u.Path

186 switch u.Scheme {

187 case httpScheme, httpsScheme:

188− log.Printf("mapping path %q => upstream %q", path, u)

188+ logger.Printf("mapping path %q => upstream %q", path, u)

189 proxy := NewWebSocketOrRestReverseProxy(u, opts, auth)

190 serveMux.Handle(path, proxy)

191

@@ -193,7 +193,7 @@ func NewOAuthProxy(opts *Options, validator func(string) bool) *OAuthProxy {

193 if u.Fragment != "" {

194 path = u.Fragment

195 }

196− log.Printf("mapping path %q => file system %q", path, u.Path)

196+ logger.Printf("mapping path %q => file system %q", path, u.Path)

197 proxy := NewFileServer(path, u.Path)

198 serveMux.Handle(path, &UpstreamProxy{path, proxy, nil, nil})

199 default:

@@ -201,7 +201,7 @@ func NewOAuthProxy(opts *Options, validator func(string) bool) *OAuthProxy {

201 }

202 }

203 for _, u := range opts.CompiledRegex {

204− log.Printf("compiled skip-auth-regex => %q", u)

204+ logger.Printf("compiled skip-auth-regex => %q", u)

205 }

206

207 redirectURL := opts.redirectURL

@@ -209,20 +209,20 @@ func NewOAuthProxy(opts *Options, validator func(string) bool) *OAuthProxy {

209 redirectURL.Path = fmt.Sprintf("%s/callback", opts.ProxyPrefix)

210 }

211

212− log.Printf("OAuthProxy configured for %s Client ID: %s", opts.provider.Data().ProviderName, opts.ClientID)

212+ logger.Printf("OAuthProxy configured for %s Client ID: %s", opts.provider.Data().ProviderName, opts.ClientID)

213 refresh := "disabled"

214 if opts.CookieRefresh != time.Duration(0) {

215 refresh = fmt.Sprintf("after %s", opts.CookieRefresh)

216 }

217

218− log.Printf("Cookie settings: name:%s secure(https):%v httponly:%v expiry:%s domain:%s path:%s refresh:%s", opts.CookieName, opts.CookieSecure, opts.CookieHTTPOnly, opts.CookieExpire, opts.CookieDomain, opts.CookiePath, refresh)

218+ logger.Printf("Cookie settings: name:%s secure(https):%v httponly:%v expiry:%s domain:%s path:%s refresh:%s", opts.CookieName, opts.CookieSecure, opts.CookieHTTPOnly, opts.CookieExpire, opts.CookieDomain, opts.CookiePath, refresh)

219

220 var cipher *cookie.Cipher

221 if opts.PassAccessToken || opts.SetAuthorization || opts.PassAuthorization || (opts.CookieRefresh != time.Duration(0)) {

222 var err error

223 cipher, err = cookie.NewCipher(secretBytes(opts.CookieSecret))

224 if err != nil {

225− log.Fatal("cookie-secret error: ", err)

225+ logger.Fatal("cookie-secret error: ", err)

226 }

227 }

228

@@ -425,7 +425,7 @@ func (p *OAuthProxy) makeCookie(req *http.Request, name string, value string, ex

425 domain = h

426 }

427 if !strings.HasSuffix(domain, p.CookieDomain) {

428− log.Printf("Warning: request host is %q but using configured cookie domain of %q", domain, p.CookieDomain)

428+ logger.Printf("Warning: request host is %q but using configured cookie domain of %q", domain, p.CookieDomain)

429 }

430 }

431

@@ -529,7 +529,6 @@ func (p *OAuthProxy) PingPage(rw http.ResponseWriter) {

529

530// ErrorPage writes an error response

531func (p *OAuthProxy) ErrorPage(rw http.ResponseWriter, code int, title string, message string) {

532− log.Printf("ErrorPage %d %s %s", code, title, message)

533 rw.WriteHeader(code)

532 rw.WriteHeader(code)

534 t := struct {

533 t := struct {

535 Title string

534 Title string

@@ -588,9 +587,10 @@ func (p *OAuthProxy) ManualSignIn(rw http.ResponseWriter, req *http.Request) (st

588 }

587 }

589 // check auth

588 // check auth

590 if p.HtpasswdFile.Validate(user, passwd) {

589 if p.HtpasswdFile.Validate(user, passwd) {

591− log.Printf("authenticated %q via HtpasswdFile", user)

590+ logger.PrintAuthf(user, req, logger.AuthSuccess, "Authenticated via HtpasswdFile")

592 return user, true

591 return user, true

593 }

592 }

593+ logger.PrintAuthf(user, req, logger.AuthFailure, "Invalid authentication via HtpasswdFile")

594 return "", false

595}

596

@@ -686,6 +686,7 @@ func (p *OAuthProxy) ServeHTTP(rw http.ResponseWriter, req *http.Request) {

686func (p *OAuthProxy) SignIn(rw http.ResponseWriter, req *http.Request) {

687 redirect, err := p.GetRedirect(req)

688 if err != nil {

689+ logger.Printf("Error obtaining redirect: %s", err.Error())

689 p.ErrorPage(rw, 500, "Internal Error", err.Error())

690 p.ErrorPage(rw, 500, "Internal Error", err.Error())

690 return

691 return

691 }

692 }

@@ -714,12 +715,14 @@ func (p *OAuthProxy) SignOut(rw http.ResponseWriter, req *http.Request) {

714func (p *OAuthProxy) OAuthStart(rw http.ResponseWriter, req *http.Request) {

715func (p *OAuthProxy) OAuthStart(rw http.ResponseWriter, req *http.Request) {

715 nonce, err := cookie.Nonce()

716 nonce, err := cookie.Nonce()

716 if err != nil {

717 if err != nil {

718+ logger.Printf("Error obtaining nonce: %s", err.Error())

717 p.ErrorPage(rw, 500, "Internal Error", err.Error())

719 p.ErrorPage(rw, 500, "Internal Error", err.Error())

718 return

720 return

719 }

721 }

720 p.SetCSRFCookie(rw, req, nonce)

722 p.SetCSRFCookie(rw, req, nonce)

721 redirect, err := p.GetRedirect(req)

723 redirect, err := p.GetRedirect(req)

722 if err != nil {

724 if err != nil {

725+ logger.Printf("Error obtaining redirect: %s", err.Error())

723 p.ErrorPage(rw, 500, "Internal Error", err.Error())

726 p.ErrorPage(rw, 500, "Internal Error", err.Error())

724 return

727 return

725 }

728 }

@@ -735,24 +738,27 @@ func (p *OAuthProxy) OAuthCallback(rw http.ResponseWriter, req *http.Request) {

735 // finish the oauth cycle

738 // finish the oauth cycle

736 err := req.ParseForm()

739 err := req.ParseForm()

737 if err != nil {

740 if err != nil {

741+ logger.Printf("Error while parsing OAuth2 callback: %s" + err.Error())

738 p.ErrorPage(rw, 500, "Internal Error", err.Error())

742 p.ErrorPage(rw, 500, "Internal Error", err.Error())

739 return

743 return

740 }

744 }

741 errorString := req.Form.Get("error")

745 errorString := req.Form.Get("error")

742 if errorString != "" {

746 if errorString != "" {

747+ logger.Printf("Error while parsing OAuth2 callback: %s ", errorString)

743 p.ErrorPage(rw, 403, "Permission Denied", errorString)

748 p.ErrorPage(rw, 403, "Permission Denied", errorString)

744 return

749 return

745 }

750 }

746

751

747 session, err := p.redeemCode(req.Host, req.Form.Get("code"))

752 session, err := p.redeemCode(req.Host, req.Form.Get("code"))

748 if err != nil {

753 if err != nil {

749− log.Printf("%s error redeeming code %s", remoteAddr, err)

754+ logger.Printf("Error redeeming code during OAuth2 callback: %s ", errorString)

750 p.ErrorPage(rw, 500, "Internal Error", "Internal Error")

755 p.ErrorPage(rw, 500, "Internal Error", "Internal Error")

751 return

756 return

752 }

757 }

753

758

754 s := strings.SplitN(req.Form.Get("state"), ":", 2)

759 s := strings.SplitN(req.Form.Get("state"), ":", 2)

755 if len(s) != 2 {

760 if len(s) != 2 {

761+ logger.Printf("Error while parsing OAuth2 state: invalid length")

756 p.ErrorPage(rw, 500, "Internal Error", "Invalid State")

762 p.ErrorPage(rw, 500, "Internal Error", "Invalid State")

757 return

763 return

758 }

764 }

@@ -760,12 +766,13 @@ func (p *OAuthProxy) OAuthCallback(rw http.ResponseWriter, req *http.Request) {

760 redirect := s[1]

766 redirect := s[1]

761 c, err := req.Cookie(p.CSRFCookieName)

767 c, err := req.Cookie(p.CSRFCookieName)

762 if err != nil {

768 if err != nil {

769+ logger.PrintAuthf(session.Email, req, logger.AuthFailure, "Invalid authentication via OAuth2: unable too obtain CSRF cookie")

763 p.ErrorPage(rw, 403, "Permission Denied", err.Error())

770 p.ErrorPage(rw, 403, "Permission Denied", err.Error())

764 return

771 return

765 }

772 }

766 p.ClearCSRFCookie(rw, req)

773 p.ClearCSRFCookie(rw, req)

767 if c.Value != nonce {

774 if c.Value != nonce {

768− log.Printf("%s csrf token mismatch, potential attack", remoteAddr)

775+ logger.PrintAuthf(session.Email, req, logger.AuthFailure, "Invalid authentication via OAuth2: csrf token mismatch, potential attack")

769 p.ErrorPage(rw, 403, "Permission Denied", "csrf failed")

776 p.ErrorPage(rw, 403, "Permission Denied", "csrf failed")

770 return

777 return

771 }

778 }

@@ -776,16 +783,16 @@ func (p *OAuthProxy) OAuthCallback(rw http.ResponseWriter, req *http.Request) {

776

783

777 // set cookie, or deny

784 // set cookie, or deny

778 if p.Validator(session.Email) && p.provider.ValidateGroup(session.Email) {

785 if p.Validator(session.Email) && p.provider.ValidateGroup(session.Email) {

779− log.Printf("%s authentication complete %s", remoteAddr, session)

786+ logger.PrintAuthf(session.Email, req, logger.AuthSuccess, "Authenticated via OAuth2: %s", session)

780 err := p.SaveSession(rw, req, session)

787 err := p.SaveSession(rw, req, session)

781 if err != nil {

788 if err != nil {

782− log.Printf("%s %s", remoteAddr, err)

789+ logger.Printf("%s %s", remoteAddr, err)

783 p.ErrorPage(rw, 500, "Internal Error", "Internal Error")

790 p.ErrorPage(rw, 500, "Internal Error", "Internal Error")

784 return

791 return

785 }

792 }

786 http.Redirect(rw, req, redirect, 302)

793 http.Redirect(rw, req, redirect, 302)

787 } else {

794 } else {

788− log.Printf("%s Permission Denied: %q is unauthorized", remoteAddr, session.Email)

795+ logger.PrintAuthf(session.Email, req, logger.AuthSuccess, "Invalid authentication via OAuth2: unauthorized")

789 p.ErrorPage(rw, 403, "Permission Denied", "Invalid Account")

796 p.ErrorPage(rw, 403, "Permission Denied", "Invalid Account")

790 }

797 }

791}

798}

@@ -827,16 +834,16 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int

827

834

828 session, sessionAge, err := p.LoadCookiedSession(req)

835 session, sessionAge, err := p.LoadCookiedSession(req)

829 if err != nil {

836 if err != nil {

830− log.Printf("%s %s", remoteAddr, err)

837+ logger.Printf("Error loading cookied session: %s", err)

831 }

838 }

832 if session != nil && sessionAge > p.CookieRefresh && p.CookieRefresh != time.Duration(0) {

839 if session != nil && sessionAge > p.CookieRefresh && p.CookieRefresh != time.Duration(0) {

833− log.Printf("%s refreshing %s old session cookie for %s (refresh after %s)", remoteAddr, sessionAge, session, p.CookieRefresh)

840+ logger.Printf("Refreshing %s old session cookie for %s (refresh after %s)", sessionAge, session, p.CookieRefresh)

834 saveSession = true

841 saveSession = true

835 }

842 }

836

843

837 var ok bool

844 var ok bool

838 if ok, err = p.provider.RefreshSessionIfNeeded(session); err != nil {

845 if ok, err = p.provider.RefreshSessionIfNeeded(session); err != nil {

839− log.Printf("%s removing session. error refreshing access token %s %s", remoteAddr, err, session)

846+ logger.Printf("%s removing session. error refreshing access token %s %s", remoteAddr, err, session)

840 clearSession = true

847 clearSession = true

841 session = nil

848 session = nil

842 } else if ok {

849 } else if ok {

@@ -845,7 +852,7 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int

845 }

852 }

846

853

847 if session != nil && session.IsExpired() {

854 if session != nil && session.IsExpired() {

848− log.Printf("%s removing session. token expired %s", remoteAddr, session)

855+ logger.Printf("Removing session: token expired %s", session)

849 session = nil

856 session = nil

850 saveSession = false

857 saveSession = false

851 clearSession = true

858 clearSession = true

@@ -853,7 +860,7 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int

853

860

854 if saveSession && !revalidated && session != nil && session.AccessToken != "" {

861 if saveSession && !revalidated && session != nil && session.AccessToken != "" {

855 if !p.provider.ValidateSessionState(session) {

862 if !p.provider.ValidateSessionState(session) {

856− log.Printf("%s removing session. error validating %s", remoteAddr, session)

863+ logger.Printf("Removing session: error validating %s", session)

857 saveSession = false

864 saveSession = false

858 session = nil

865 session = nil

859 clearSession = true

866 clearSession = true

@@ -861,7 +868,7 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int

861 }

868 }

862

869

863 if session != nil && session.Email != "" && !p.Validator(session.Email) {

870 if session != nil && session.Email != "" && !p.Validator(session.Email) {

864− log.Printf("%s Permission Denied: removing session %s", remoteAddr, session)

871+ logger.Printf(session.Email, req, logger.AuthFailure, "Invalid authentication via session: removing session %s", session)

865 session = nil

872 session = nil

866 saveSession = false

873 saveSession = false

867 clearSession = true

874 clearSession = true

@@ -870,7 +877,7 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int

870 if saveSession && session != nil {

877 if saveSession && session != nil {

871 err = p.SaveSession(rw, req, session)

878 err = p.SaveSession(rw, req, session)

872 if err != nil {

879 if err != nil {

873− log.Printf("%s %s", remoteAddr, err)

880+ logger.PrintAuthf(session.Email, req, logger.AuthError, "Save session error %s", err)

874 return http.StatusInternalServerError

881 return http.StatusInternalServerError

875 }

882 }

876 }

883 }

@@ -882,7 +889,7 @@ func (p *OAuthProxy) Authenticate(rw http.ResponseWriter, req *http.Request) int

882 if session == nil {

889 if session == nil {

883 session, err = p.CheckBasicAuth(req)

890 session, err = p.CheckBasicAuth(req)

884 if err != nil {

891 if err != nil {

885− log.Printf("%s %s", remoteAddr, err)

892+ logger.Printf("Error during basic auth validation: %s", err)

886 }

893 }

887 }

894 }

888

895

@@ -958,10 +965,11 @@ func (p *OAuthProxy) CheckBasicAuth(req *http.Request) (*providers.SessionState,

958 return nil, fmt.Errorf("invalid format %s", b)

965 return nil, fmt.Errorf("invalid format %s", b)

959 }

966 }

960 if p.HtpasswdFile.Validate(pair[0], pair[1]) {

967 if p.HtpasswdFile.Validate(pair[0], pair[1]) {

961− log.Printf("authenticated %q via basic auth", pair[0])

968+ logger.PrintAuthf(pair[0], req, logger.AuthSuccess, "Authenticated via basic auth and HTpasswd File")

962 return &providers.SessionState{User: pair[0]}, nil

969 return &providers.SessionState{User: pair[0]}, nil

963 }

970 }

964− return nil, fmt.Errorf("%s not in HtpasswdFile", pair[0])

971+ logger.PrintAuthf(pair[0], req, logger.AuthFailure, "Invalid authentication via basic auth: not in Htpasswd File")

972+ return nil, nil

965}

973}

966

974

967// isAjax checks if a request is an ajax request

975// isAjax checks if a request is an ajax request

oauthproxy_test.go+4−4

@@ -5,7 +5,6 @@ import (

5 "encoding/base64"

6 "io"

7 "io/ioutil"

8− "log"

9 "net"

8 "net"

10 "net/http"

9 "net/http"

11 "net/http/httptest"

10 "net/http/httptest"

@@ -16,6 +15,7 @@ import (

16 "time"

15 "time"

17

16

18 "github.com/mbland/hmacauth"

17 "github.com/mbland/hmacauth"

18+ "github.com/pusher/oauth2_proxy/logger"

19 "github.com/pusher/oauth2_proxy/providers"

20 "github.com/stretchr/testify/assert"

21 "github.com/stretchr/testify/require"

@@ -23,7 +23,7 @@ import (

23)

24

25func init() {

26− log.SetFlags(log.Ldate | log.Ltime | log.Lshortfile)

26+ logger.SetFlags(logger.Lshortfile)

27

28}

29

@@ -263,7 +263,7 @@ func (tp *TestProvider) ValidateSessionState(session *providers.SessionState) bo

263

264func TestBasicAuthPassword(t *testing.T) {

265 providerServer := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {

266− log.Printf("%#v", r)

266+ logger.Printf("%#v", r)

267 var payload string

268 switch r.URL.Path {

269 case "/oauth/token":

@@ -355,7 +355,7 @@ func NewPassAccessTokenTest(opts PassAccessTokenTestOptions) *PassAccessTokenTes

355

356 t.providerServer = httptest.NewServer(

357 http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {

358− log.Printf("%#v", r)

358+ logger.Printf("%#v", r)

359 var payload string

360 switch r.URL.Path {

361 case "/oauth/token":

options.go+94−24

@@ -17,7 +17,9 @@ import (

17 oidc "github.com/coreos/go-oidc"

18 "github.com/dgrijalva/jwt-go"

19 "github.com/mbland/hmacauth"

20+ "github.com/pusher/oauth2_proxy/logger"

20 "github.com/pusher/oauth2_proxy/providers"

21 "github.com/pusher/oauth2_proxy/providers"

22+ "gopkg.in/natefinch/lumberjack.v2"

21)

23)

22

24

23// Options holds Configuration Options that can be set by Command Line Flag,

25// Options holds Configuration Options that can be set by Command Line Flag,

@@ -85,8 +87,19 @@ type Options struct {

85 Scope string `flag:"scope" cfg:"scope" env:"OAUTH2_PROXY_SCOPE"`

87 Scope string `flag:"scope" cfg:"scope" env:"OAUTH2_PROXY_SCOPE"`

86 ApprovalPrompt string `flag:"approval-prompt" cfg:"approval_prompt" env:"OAUTH2_PROXY_APPROVAL_PROMPT"`

88 ApprovalPrompt string `flag:"approval-prompt" cfg:"approval_prompt" env:"OAUTH2_PROXY_APPROVAL_PROMPT"`

87

89

90+ // Configuration values for logging

91+ LoggingFilename string `flag:"logging-filename" cfg:"logging_filename" env:"OAUTH2_LOGGING_FILENAME"`

92+ LoggingMaxSize int `flag:"logging-max-size" cfg:"logging_max_size" env:"OAUTH2_LOGGING_MAX_SIZE"`

93+ LoggingMaxAge int `flag:"logging-max-age" cfg:"logging_max_age" env:"OAUTH2_LOGGING_MAX_AGE"`

94+ LoggingMaxBackups int `flag:"logging-max-backups" cfg:"logging_max_backups" env:"OAUTH2_LOGGING_MAX_BACKUPS"`

95+ LoggingLocalTime bool `flag:"logging-local-time" cfg:"logging_local_time" env:"OAUTH2_LOGGING_LOCAL_TIME"`

96+ LoggingCompress bool `flag:"logging-compress" cfg:"logging_compress" env:"OAUTH2_LOGGING_COMPRESS"`

97+ StandardLogging bool `flag:"standard-logging" cfg:"standard_logging" env:"OAUTH2_STANDARD_LOGGING"`

98+ StandardLoggingFormat string `flag:"standard-logging-format" cfg:"standard_logging_format" env:"OAUTH2_STANDARD_LOGGING_FORMAT"`

88− RequestLogging bool `flag:"request-logging" cfg:"request_logging" env:"OAUTH2_PROXY_REQUEST_LOGGING"`

99+ RequestLogging bool `flag:"request-logging" cfg:"request_logging" env:"OAUTH2_REQUEST_LOGGING"`

89− RequestLoggingFormat string `flag:"request-logging-format" cfg:"request_logging_format" env:"OAUTH2_PROXY_REQUEST_LOGGING_FORMAT"`

100+ RequestLoggingFormat string `flag:"request-logging-format" cfg:"request_logging_format" env:"OAUTH2_REQUEST_LOGGING_FORMAT"`

101+ AuthLogging bool `flag:"auth-logging" cfg:"auth_logging" env:"OAUTH2_LOGGING_AUTH_LOGGING"`

102+ AuthLoggingFormat string `flag:"auth-logging-format" cfg:"auth_logging_format" env:"OAUTH2_AUTH_LOGGING_FORMAT"`

90

103

91 SignatureKey string `flag:"signature-key" cfg:"signature_key" env:"OAUTH2_PROXY_SIGNATURE_KEY"`

104 SignatureKey string `flag:"signature-key" cfg:"signature_key" env:"OAUTH2_PROXY_SIGNATURE_KEY"`

92 AcrValues string `flag:"acr-values" cfg:"acr_values" env:"OAUTH2_PROXY_ACR_VALUES"`

105 AcrValues string `flag:"acr-values" cfg:"acr_values" env:"OAUTH2_PROXY_ACR_VALUES"`

@@ -113,28 +126,38 @@ type SignatureData struct {

113// NewOptions constructs a new Options with defaulted values

126// NewOptions constructs a new Options with defaulted values

114func NewOptions() *Options {

127func NewOptions() *Options {

115 return &Options{

128 return &Options{

116− ProxyPrefix: "/oauth2",

129+ ProxyPrefix: "/oauth2",

117− ProxyWebSockets: true,

130+ ProxyWebSockets: true,

118− HTTPAddress: "127.0.0.1:4180",

131+ HTTPAddress: "127.0.0.1:4180",

119− HTTPSAddress: ":443",

132+ HTTPSAddress: ":443",

120− DisplayHtpasswdForm: true,

133+ DisplayHtpasswdForm: true,

121− CookieName: "_oauth2_proxy",

134+ CookieName: "_oauth2_proxy",

122− CookieSecure: true,

135+ CookieSecure: true,

123− CookieHTTPOnly: true,

136+ CookieHTTPOnly: true,

124− CookieExpire: time.Duration(168) * time.Hour,

137+ CookieExpire: time.Duration(168) * time.Hour,

125− CookieRefresh: time.Duration(0),

138+ CookieRefresh: time.Duration(0),

126− SetXAuthRequest: false,

139+ SetXAuthRequest: false,

127− SkipAuthPreflight: false,

140+ SkipAuthPreflight: false,

128− PassBasicAuth: true,

141+ PassBasicAuth: true,

129− PassUserHeaders: true,

142+ PassUserHeaders: true,

130− PassAccessToken: false,

143+ PassAccessToken: false,

131− PassHostHeader: true,

144+ PassHostHeader: true,

132− SetAuthorization: false,

145+ SetAuthorization: false,

133− PassAuthorization: false,

146+ PassAuthorization: false,

134− ApprovalPrompt: "force",

147+ ApprovalPrompt: "force",

148+ SkipOIDCDiscovery: false,

149+ LoggingFilename: "",

150+ LoggingMaxSize: 100,

151+ LoggingMaxAge: 7,

152+ LoggingMaxBackups: 0,

153+ LoggingLocalTime: true,

154+ LoggingCompress: false,

155+ StandardLogging: true,

156+ StandardLoggingFormat: logger.DefaultStandardLoggingFormat,

135− RequestLogging: true,

157+ RequestLogging: true,

136− SkipOIDCDiscovery: false,

137− RequestLoggingFormat: defaultRequestLoggingFormat,

158+ RequestLoggingFormat: logger.DefaultRequestLoggingFormat,

159+ AuthLogging: true,

160+ AuthLoggingFormat: logger.DefaultAuthLoggingFormat,

138 }

161 }

139}

162}

140

163

@@ -285,6 +308,7 @@ func (o *Options) Validate() error {

285

308

286 msgs = parseSignatureKey(o, msgs)

309 msgs = parseSignatureKey(o, msgs)

287 msgs = validateCookieName(o, msgs)

310 msgs = validateCookieName(o, msgs)

311+ msgs = setupLogger(o, msgs)

288

312

289 if len(msgs) != 0 {

313 if len(msgs) != 0 {

290 return fmt.Errorf("Invalid configuration:\n %s",

314 return fmt.Errorf("Invalid configuration:\n %s",

@@ -414,3 +438,49 @@ func secretBytes(secret string) []byte {

414 }

438 }

415 return []byte(secret)

439 return []byte(secret)

416}

440}

441+

442+func setupLogger(o *Options, msgs []string) []string {

443+ // Setup the log file

444+ if len(o.LoggingFilename) > 0 {

445+ // Validate that the file/dir can be written

446+ file, err := os.OpenFile(o.LoggingFilename, os.O_WRONLY|os.O_CREATE, 0666)

447+ if err != nil {

448+ if os.IsPermission(err) {

449+ return append(msgs, "unable to write to log file: "+o.LoggingFilename)

450+ }

451+ }

452+ file.Close()

453+

454+ logger.Printf("Redirecting logging to file: %s", o.LoggingFilename)

455+

456+ logWriter := &lumberjack.Logger{

457+ Filename: o.LoggingFilename,

458+ MaxSize: o.LoggingMaxSize, // megabytes

459+ MaxAge: o.LoggingMaxAge, // days

460+ MaxBackups: o.LoggingMaxBackups,

461+ LocalTime: o.LoggingLocalTime,

462+ Compress: o.LoggingCompress,

463+ }

464+

465+ logger.SetOutput(logWriter)

466+ }

467+

468+ // Supply a sanity warning to the logger if all logging is disabled

469+ if !o.StandardLogging && !o.AuthLogging && !o.RequestLogging {

470+ logger.Print("Warning: Logging disabled. No further logs will be shown.")

471+ }

472+

473+ // Pass configuration values to the standard logger

474+ logger.SetStandardEnabled(o.StandardLogging)

475+ logger.SetAuthEnabled(o.AuthLogging)

476+ logger.SetReqEnabled(o.RequestLogging)

477+ logger.SetStandardTemplate(o.StandardLoggingFormat)

478+ logger.SetAuthTemplate(o.AuthLoggingFormat)

479+ logger.SetReqTemplate(o.RequestLoggingFormat)

480+

481+ if !o.LoggingLocalTime {

482+ logger.SetFlags(logger.Flags() | logger.LUTC)

483+ }

484+

485+ return msgs

486+}

providers/azure.go+3−3

@@ -3,12 +3,12 @@ package providers

3import (

4 "errors"

5 "fmt"

6− "log"

7 "net/http"

6 "net/http"

8 "net/url"

7 "net/url"

9

8

10 "github.com/bitly/go-simplejson"

9 "github.com/bitly/go-simplejson"

11 "github.com/pusher/oauth2_proxy/api"

10 "github.com/pusher/oauth2_proxy/api"

11+ "github.com/pusher/oauth2_proxy/logger"

12)

13

14// AzureProvider represents an Azure based Identity Provider

@@ -116,12 +116,12 @@ func (p *AzureProvider) GetEmailAddress(s *SessionState) (string, error) {

116 email, err = json.Get("userPrincipalName").String()

117

118 if err != nil {

119− log.Printf("failed making request %s", err)

119+ logger.Printf("failed making request %s", err)

120 return "", err

121 }

122

123 if email == "" {

124− log.Printf("failed to get email address")

124+ logger.Printf("failed to get email address")

125 return "", err

126 }

127

providers/github.go+9−8

@@ -4,12 +4,13 @@ import (

4 "encoding/json"

5 "fmt"

6 "io/ioutil"

7− "log"

8 "net/http"

7 "net/http"

9 "net/url"

8 "net/url"

10 "path"

9 "path"

11 "strconv"

10 "strconv"

12 "strings"

11 "strings"

12+

13+ "github.com/pusher/oauth2_proxy/logger"

13)

14)

14

15

15// GitHubProvider represents an GitHub based Identity Provider

16// GitHubProvider represents an GitHub based Identity Provider

@@ -116,13 +117,13 @@ func (p *GitHubProvider) hasOrg(accessToken string) (bool, error) {

116 var presentOrgs []string

117 var presentOrgs []string

117 for _, org := range orgs {

118 for _, org := range orgs {

118 if p.Org == org.Login {

119 if p.Org == org.Login {

119− log.Printf("Found Github Organization: %q", org.Login)

120+ logger.Printf("Found Github Organization: %q", org.Login)

120 return true, nil

121 return true, nil

121 }

122 }

122 presentOrgs = append(presentOrgs, org.Login)

123 presentOrgs = append(presentOrgs, org.Login)

123 }

124 }

124

125

125− log.Printf("Missing Organization:%q in %v", p.Org, presentOrgs)

126+ logger.Printf("Missing Organization:%q in %v", p.Org, presentOrgs)

126 return false, nil

127 return false, nil

127}

128}

128

129

@@ -179,7 +180,7 @@ func (p *GitHubProvider) hasOrgAndTeam(accessToken string) (bool, error) {

179 ts := strings.Split(p.Team, ",")

180 ts := strings.Split(p.Team, ",")

180 for _, t := range ts {

181 for _, t := range ts {

181 if t == team.Slug {

182 if t == team.Slug {

182− log.Printf("Found Github Organization:%q Team:%q (Name:%q)", team.Org.Login, team.Slug, team.Name)

183+ logger.Printf("Found Github Organization:%q Team:%q (Name:%q)", team.Org.Login, team.Slug, team.Name)

183 return true, nil

184 return true, nil

184 }

185 }

186 }

@@ -187,13 +188,13 @@ func (p *GitHubProvider) hasOrgAndTeam(accessToken string) (bool, error) {

187 }

188 }

189 }

189 if hasOrg {

190 if hasOrg {

190− log.Printf("Missing Team:%q from Org:%q in teams: %v", p.Team, p.Org, presentTeams)

191+ logger.Printf("Missing Team:%q from Org:%q in teams: %v", p.Team, p.Org, presentTeams)

191 } else {

192 } else {

192 var allOrgs []string

193 var allOrgs []string

193 for org := range presentOrgs {

194 for org := range presentOrgs {

194 allOrgs = append(allOrgs, org)

195 allOrgs = append(allOrgs, org)

195 }

196 }

196− log.Printf("Missing Organization:%q in %#v", p.Org, allOrgs)

197+ logger.Printf("Missing Organization:%q in %#v", p.Org, allOrgs)

197 }

198 }

198 return false, nil

199 return false, nil

199}

200}

@@ -242,7 +243,7 @@ func (p *GitHubProvider) GetEmailAddress(s *SessionState) (string, error) {

242 resp.StatusCode, endpoint.String(), body)

243 resp.StatusCode, endpoint.String(), body)

243 }

244 }

244

245

245− log.Printf("got %d from %q %s", resp.StatusCode, endpoint.String(), body)

246+ logger.Printf("got %d from %q %s", resp.StatusCode, endpoint.String(), body)

246

247

247 if err := json.Unmarshal(body, &emails); err != nil {

248 if err := json.Unmarshal(body, &emails); err != nil {

248 return "", fmt.Errorf("%s unmarshaling %s", err, body)

249 return "", fmt.Errorf("%s unmarshaling %s", err, body)

@@ -292,7 +293,7 @@ func (p *GitHubProvider) GetUserName(s *SessionState) (string, error) {

292 resp.StatusCode, endpoint.String(), body)

293 resp.StatusCode, endpoint.String(), body)

293 }

294 }

294

295

295− log.Printf("got %d from %q %s", resp.StatusCode, endpoint.String(), body)

296+ logger.Printf("got %d from %q %s", resp.StatusCode, endpoint.String(), body)

296

297

297 if err := json.Unmarshal(body, &user); err != nil {

298 if err := json.Unmarshal(body, &user); err != nil {

298 return "", fmt.Errorf("%s unmarshaling %s", err, body)

299 return "", fmt.Errorf("%s unmarshaling %s", err, body)

providers/gitlab.go+3−3

@@ -1,11 +1,11 @@

1package providers

2

3import (

4− "log"

5 "net/http"

4 "net/http"

6 "net/url"

5 "net/url"

7

6

8 "github.com/pusher/oauth2_proxy/api"

7 "github.com/pusher/oauth2_proxy/api"

8+ "github.com/pusher/oauth2_proxy/logger"

9)

10

11// GitLabProvider represents an GitLab based Identity Provider

@@ -49,12 +49,12 @@ func (p *GitLabProvider) GetEmailAddress(s *SessionState) (string, error) {

49 req, err := http.NewRequest("GET",

50 p.ValidateURL.String()+"?access_token="+s.AccessToken, nil)

51 if err != nil {

52− log.Printf("failed building request %s", err)

52+ logger.Printf("failed building request %s", err)

53 return "", err

54 }

55 json, err := api.Request(req)

56 if err != nil {

57− log.Printf("failed making request %s", err)

57+ logger.Printf("failed making request %s", err)

58 return "", err

59 }

60 return json.Get("email").String()

providers/google.go+8−8

@@ -8,12 +8,12 @@ import (

8 "fmt"

9 "io"

10 "io/ioutil"

11− "log"

12 "net/http"

11 "net/http"

13 "net/url"

12 "net/url"

14 "strings"

13 "strings"

15 "time"

14 "time"

16

15

16+ "github.com/pusher/oauth2_proxy/logger"

17 "golang.org/x/oauth2"

18 "golang.org/x/oauth2/google"

19 admin "google.golang.org/api/admin/directory/v1"

@@ -167,18 +167,18 @@ func (p *GoogleProvider) SetGroupRestriction(groups []string, adminEmail string,

167func getAdminService(adminEmail string, credentialsReader io.Reader) *admin.Service {

168 data, err := ioutil.ReadAll(credentialsReader)

169 if err != nil {

170− log.Fatal("can't read Google credentials file:", err)

170+ logger.Fatal("can't read Google credentials file:", err)

171 }

172 conf, err := google.JWTConfigFromJSON(data, admin.AdminDirectoryUserReadonlyScope, admin.AdminDirectoryGroupReadonlyScope)

173 if err != nil {

174− log.Fatal("can't load Google credentials file:", err)

174+ logger.Fatal("can't load Google credentials file:", err)

175 }

176 conf.Subject = adminEmail

177

178 client := conf.Client(oauth2.NoContext)

179 adminService, err := admin.New(client)

180 if err != nil {

181− log.Fatal(err)

181+ logger.Fatal(err)

182 }

183 return adminService

184}

@@ -186,7 +186,7 @@ func getAdminService(adminEmail string, credentialsReader io.Reader) *admin.Serv

186func userInGroup(service *admin.Service, groups []string, email string) bool {

187 user, err := fetchUser(service, email)

188 if err != nil {

189− log.Printf("error fetching user: %v", err)

189+ logger.Printf("error fetching user: %v", err)

190 return false

191 }

192 id := user.Id

@@ -196,9 +196,9 @@ func userInGroup(service *admin.Service, groups []string, email string) bool {

196 members, err := fetchGroupMembers(service, group)

197 if err != nil {

198 if err, ok := err.(*googleapi.Error); ok && err.Code == 404 {

199− log.Printf("error fetching members for group %s: group does not exist", group)

199+ logger.Printf("error fetching members for group %s: group does not exist", group)

200 } else {

201− log.Printf("error fetching group members: %v", err)

201+ logger.Printf("error fetching group members: %v", err)

202 return false

203 }

204 }

@@ -274,7 +274,7 @@ func (p *GoogleProvider) RefreshSessionIfNeeded(s *SessionState) (bool, error) {

274 s.AccessToken = newToken

275 s.IDToken = newIDToken

276 s.ExpiresOn = time.Now().Add(duration).Truncate(time.Second)

277− log.Printf("refreshed access token %s (expired on %s)", s, origExpiration)

277+ logger.Printf("refreshed access token %s (expired on %s)", s, origExpiration)

278 return true, nil

279}

280

providers/internal_util.go+7−7

@@ -2,11 +2,11 @@ package providers

2

3import (

4 "io/ioutil"

5− "log"

6 "net/http"

5 "net/http"

7 "net/url"

6 "net/url"

8

7

9 "github.com/pusher/oauth2_proxy/api"

8 "github.com/pusher/oauth2_proxy/api"

9+ "github.com/pusher/oauth2_proxy/logger"

10)

11

12// stripToken is a helper function to obfuscate "access_token"

@@ -24,14 +24,14 @@ func stripToken(endpoint string) string {

24func stripParam(param, endpoint string) string {

25 u, err := url.Parse(endpoint)

26 if err != nil {

27− log.Printf("error attempting to strip %s: %s", param, err)

27+ logger.Printf("error attempting to strip %s: %s", param, err)

28 return endpoint

29 }

30

31 if u.RawQuery != "" {

32 values, err := url.ParseQuery(u.RawQuery)

33 if err != nil {

34− log.Printf("error attempting to strip %s: %s", param, err)

34+ logger.Printf("error attempting to strip %s: %s", param, err)

35 return u.String()

36 }

37

@@ -57,18 +57,18 @@ func validateToken(p Provider, accessToken string, header http.Header) bool {

57 }

58 resp, err := api.RequestUnparsedResponse(endpoint, header)

59 if err != nil {

60− log.Printf("GET %s", stripToken(endpoint))

60+ logger.Printf("GET %s", stripToken(endpoint))

61− log.Printf("token validation request failed: %s", err)

61+ logger.Printf("token validation request failed: %s", err)

62 return false

63 }

64

65 body, _ := ioutil.ReadAll(resp.Body)

66 resp.Body.Close()

67− log.Printf("%d GET %s %s", resp.StatusCode, stripToken(endpoint), body)

67+ logger.Printf("%d GET %s %s", resp.StatusCode, stripToken(endpoint), body)

68

69 if resp.StatusCode == 200 {

70 return true

71 }

72− log.Printf("token validation request failed: status %d - %s", resp.StatusCode, body)

72+ logger.Printf("token validation request failed: status %d - %s", resp.StatusCode, body)

73 return false

74}

templates.go+6−5

@@ -2,18 +2,19 @@ package main

2

3import (

4 "html/template"

5− "log"

6 "path"

5 "path"

6+

7+ "github.com/pusher/oauth2_proxy/logger"

7)

8)

8

9

9func loadTemplates(dir string) *template.Template {

10func loadTemplates(dir string) *template.Template {

10 if dir == "" {

11 if dir == "" {

11 return getTemplates()

12 return getTemplates()

12 }

13 }

13− log.Printf("using custom template directory %q", dir)

14+ logger.Printf("using custom template directory %q", dir)

14 t, err := template.New("").ParseFiles(path.Join(dir, "sign_in.html"), path.Join(dir, "error.html"))

15 t, err := template.New("").ParseFiles(path.Join(dir, "sign_in.html"), path.Join(dir, "error.html"))

15 if err != nil {

16 if err != nil {

16− log.Fatalf("failed parsing template %s", err)

17+ logger.Fatalf("failed parsing template %s", err)

17 }

18 }

18 return t

19 return t

19}

20}

@@ -151,7 +152,7 @@ func getTemplates() *template.Template {

151</html>

152</html>

152{{end}}`)

153{{end}}`)

153 if err != nil {

154 if err != nil {

154− log.Fatalf("failed parsing template %s", err)

155+ logger.Fatalf("failed parsing template %s", err)

155 }

156 }

156

157

157 t, err = t.Parse(`{{define "error.html"}}

158 t, err = t.Parse(`{{define "error.html"}}

@@ -169,7 +170,7 @@ func getTemplates() *template.Template {

169</body>

170</body>

170</html>{{end}}`)

171</html>{{end}}`)

171 if err != nil {

172 if err != nil {

172− log.Fatalf("failed parsing template %s", err)

173+ logger.Fatalf("failed parsing template %s", err)

173 }

174 }

174 return t

175 return t

175}

176}

validator.go+5−4

@@ -3,11 +3,12 @@ package main

3import (

4 "encoding/csv"

5 "fmt"

6− "log"

7 "os"

6 "os"

8 "strings"

7 "strings"

9 "sync/atomic"

8 "sync/atomic"

10 "unsafe"

9 "unsafe"

10+

11+ "github.com/pusher/oauth2_proxy/logger"

11)

12)

12

13

13// UserMap holds information from the authenticated emails file

14// UserMap holds information from the authenticated emails file

@@ -22,7 +23,7 @@ func NewUserMap(usersFile string, done <-chan bool, onUpdate func()) *UserMap {

22 m := make(map[string]bool)

23 m := make(map[string]bool)

23 atomic.StorePointer(&um.m, unsafe.Pointer(&m))

24 atomic.StorePointer(&um.m, unsafe.Pointer(&m))

24 if usersFile != "" {

25 if usersFile != "" {

25− log.Printf("using authenticated emails file %s", usersFile)

26+ logger.Printf("using authenticated emails file %s", usersFile)

26 WatchForUpdates(usersFile, done, func() {

27 WatchForUpdates(usersFile, done, func() {

27 um.LoadAuthenticatedEmailsFile()

28 um.LoadAuthenticatedEmailsFile()

28 onUpdate()

29 onUpdate()

@@ -44,7 +45,7 @@ func (um *UserMap) IsValid(email string) (result bool) {

44func (um *UserMap) LoadAuthenticatedEmailsFile() {

45func (um *UserMap) LoadAuthenticatedEmailsFile() {

45 r, err := os.Open(um.usersFile)

46 r, err := os.Open(um.usersFile)

46 if err != nil {

47 if err != nil {

47− log.Fatalf("failed opening authenticated-emails-file=%q, %s", um.usersFile, err)

48+ logger.Fatalf("failed opening authenticated-emails-file=%q, %s", um.usersFile, err)

48 }

49 }

49 defer r.Close()

50 defer r.Close()

50 csvReader := csv.NewReader(r)

51 csvReader := csv.NewReader(r)

@@ -53,7 +54,7 @@ func (um *UserMap) LoadAuthenticatedEmailsFile() {

53 csvReader.TrimLeadingSpace = true

54 csvReader.TrimLeadingSpace = true

54 records, err := csvReader.ReadAll()

55 records, err := csvReader.ReadAll()

55 if err != nil {

56 if err != nil {

56− log.Printf("error reading authenticated-emails-file=%q, %s", um.usersFile, err)

57+ logger.Printf("error reading authenticated-emails-file=%q, %s", um.usersFile, err)

57 return

58 return

58 }

59 }

59 updated := make(map[string]bool)

60 updated := make(map[string]bool)

watcher.go+9−9

@@ -3,11 +3,11 @@

3package main

4

5import (

6− "log"

7 "os"

6 "os"

8 "path/filepath"

7 "path/filepath"

9 "time"

8 "time"

10

9

10+ "github.com/pusher/oauth2_proxy/logger"

11 fsnotify "gopkg.in/fsnotify/fsnotify.v1"

12)

13

@@ -24,7 +24,7 @@ func WaitForReplacement(filename string, op fsnotify.Op,

24 for {

25 if _, err := os.Stat(filename); err == nil {

26 if err := watcher.Add(filename); err == nil {

27− log.Printf("watching resumed for %s", filename)

27+ logger.Printf("watching resumed for %s", filename)

28 return

29 }

30 }

@@ -37,14 +37,14 @@ func WatchForUpdates(filename string, done <-chan bool, action func()) {

37 filename = filepath.Clean(filename)

38 watcher, err := fsnotify.NewWatcher()

39 if err != nil {

40− log.Fatal("failed to create watcher for ", filename, ": ", err)

40+ logger.Fatal("failed to create watcher for ", filename, ": ", err)

41 }

42 go func() {

43 defer watcher.Close()

44 for {

45 select {

46 case _ = <-done:

47− log.Printf("Shutting down watcher for: %s", filename)

47+ logger.Printf("Shutting down watcher for: %s", filename)

48 return

49 case event := <-watcher.Events:

50 // On Arch Linux, it appears Chmod events precede Remove events,

@@ -53,19 +53,19 @@ func WatchForUpdates(filename string, done <-chan bool, action func()) {

53 // UserMap.LoadAuthenticatedEmailsFile()) crashes when the file

54 // can't be opened.

55 if event.Op&(fsnotify.Remove|fsnotify.Rename|fsnotify.Chmod) != 0 {

56− log.Printf("watching interrupted on event: %s", event)

56+ logger.Printf("watching interrupted on event: %s", event)

57 watcher.Remove(filename)

58 WaitForReplacement(filename, event.Op, watcher)

59 }

60− log.Printf("reloading after event: %s", event)

60+ logger.Printf("reloading after event: %s", event)

61 action()

62 case err = <-watcher.Errors:

63− log.Printf("error watching %s: %s", filename, err)

63+ logger.Printf("error watching %s: %s", filename, err)

64 }

65 }

66 }()

67 if err = watcher.Add(filename); err != nil {

68− log.Fatal("failed to add ", filename, " to watcher: ", err)

68+ logger.Fatal("failed to add ", filename, " to watcher: ", err)

69 }

70− log.Printf("watching %s for updates", filename)

70+ logger.Printf("watching %s for updates", filename)

71}

watcher_unsupported.go+2−4

@@ -2,11 +2,9 @@

2

3package main

4

5−import (

5+import "github.com/pusher/oauth2_proxy/logger"

6− "log"

7−)

8

6

9func WatchForUpdates(filename string, done <-chan bool, action func()) {

7func WatchForUpdates(filename string, done <-chan bool, action func()) {

10− log.Printf("file watching not implemented on this platform")

8+ logger.Printf("file watching not implemented on this platform")

11 go func() { <-done }()

9 go func() { <-done }()

12}

10}