From c1267bb92dbc14368e200a61906e9f562fc882fc Mon Sep 17 00:00:00 2001 From: Nick Meves Date: Sun, 21 Mar 2021 11:20:57 -0700 Subject: [PATCH] Request ID Logging (#1087) * Add RequestID to the RequestScope * Expose RequestID to auth & request loggers * Use the RequestID in templated HTML pages * Allow customizing the RequestID header * Document new Request ID support * Add more cases to scope/requestID tests * Split Get vs Generate RequestID funtionality * Add {{.RequestID}} to the request logger tests * Move RequestID management to RequestScope * Use HTML escape instead of sanitization for Request ID rendering --- CHANGELOG.md | 5 +- docs/docs/configuration/overview.md | 13 ++-- go.mod | 1 + go.sum | 15 +---- oauthproxy.go | 13 +++- pkg/apis/middleware/scope.go | 4 ++ pkg/apis/options/logging.go | 3 + pkg/app/pagewriter/error.html | 9 ++- pkg/app/pagewriter/error_page.go | 38 +++++++++-- pkg/app/pagewriter/error_page_test.go | 62 ++++++++++++++--- pkg/app/pagewriter/pagewriter.go | 4 +- pkg/app/pagewriter/pagewriter_suite_test.go | 2 + pkg/app/pagewriter/pagewriter_test.go | 20 ++++-- pkg/app/pagewriter/sign_in_page.go | 11 ++- pkg/app/pagewriter/sign_in_page_test.go | 16 +++-- pkg/app/pagewriter/templates_test.go | 2 + pkg/logger/logger.go | 11 ++- pkg/middleware/request_logger_test.go | 13 ++-- pkg/middleware/scope.go | 15 ++++- pkg/middleware/scope_test.go | 74 ++++++++++++++++++--- pkg/middleware/stored_session_test.go | 1 + pkg/requests/util/util.go | 12 +++- pkg/upstream/http_test.go | 2 +- 23 files changed, 274 insertions(+), 72 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 72268578..6b91fd81 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,9 +4,9 @@ ## Important Notes - - [#1103](https://github.com/oauth2-proxy/oauth2-proxy/pull/1103) Upstream request signatures via `--signature-key` is deprecated. Support will be removed completely in v8.0.0. +- [1087](https://github.com/oauth2-proxy/oauth2-proxy/pull/1087) The default logging templates have been updated to include {{.RequestID}} ## Breaking Changes @@ -14,7 +14,8 @@ - [#1045](https://github.com/oauth2-proxy/oauth2-proxy/pull/1045) Ensure redirect URI always has a scheme (@JoelSpeed) - [#1103](https://github.com/oauth2-proxy/oauth2-proxy/pull/1103) Deprecate upstream request signatures (@NickMeves) -- [#914](https://github.com/oauth2-proxy/oauth2-proxy/pull/914) Extract email from id_token for azure provider when oidc is configured +- [1087](https://github.com/oauth2-proxy/oauth2-proxy/pull/1087) Support Request ID in logging (@NickMeves) +- [#914](https://github.com/oauth2-proxy/oauth2-proxy/pull/914) Extract email from id_token for azure provider when oidc is configured (@weinong) - [#1047](https://github.com/oauth2-proxy/oauth2-proxy/pull/1047) Refactor HTTP Server and add ServerGroup to handle graceful shutdown of multiple servers (@JoelSpeed) - [#1070](https://github.com/oauth2-proxy/oauth2-proxy/pull/1070) Refactor logging middleware to middleware package (@NickMeves) - [#1064](https://github.com/oauth2-proxy/oauth2-proxy/pull/1064) Add support for setting groups on session when using basic auth (@stefansedich) diff --git a/docs/docs/configuration/overview.md b/docs/docs/configuration/overview.md index 5a4c7e2d..ddfee3fc 100644 --- a/docs/docs/configuration/overview.md +++ b/docs/docs/configuration/overview.md @@ -108,6 +108,7 @@ An example [oauth2-proxy.cfg](https://github.com/oauth2-proxy/oauth2-proxy/blob/ | `--redis-sentinel-connection-urls` | string \| list | List of Redis sentinel connection URLs (e.g. `redis://HOST[:PORT]`). Used in conjunction with `--redis-use-sentinel` | | | `--redis-use-cluster` | bool | Connect to redis cluster. Must set `--redis-cluster-connection-urls` to use this feature | false | | `--redis-use-sentinel` | bool | Connect to redis via sentinels. Must set `--redis-sentinel-master-name` and `--redis-sentinel-connection-urls` to use this feature | false | +| `--request-id-header` | string | Request header to use as the request ID in logging | X-Request-Id | | `--request-logging` | bool | Log requests | true | | `--request-logging-format` | string | Template for request log lines | see [Logging Configuration](#logging-configuration) | | `--resource` | string | The resource that is protected (Azure AD only) | | @@ -184,7 +185,7 @@ Logging of requests to the `/ping` endpoint (or using `--ping-user-agent`) can b 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: ``` - - [19/Mar/2015:17:20:19 -0400] [] + - - [19/Mar/2015:17:20:19 -0400] [] ``` The status block will contain one of the below strings: @@ -197,7 +198,7 @@ If you require a different format than that, you can configure it with the `--au The default format is configured as follows: ``` -{{.Client}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}} +{{.Client}} - {{.RequestID}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}} ``` Available variables for auth logging: @@ -206,26 +207,27 @@ Available variables for auth logging: | --- | --- | --- | | Client | 74.125.224.72 | The client/remote IP address. Will use the X-Real-IP header it if exists & reverse-proxy is set to true. | | Host | domain.com | The value of the Host header. | +| Message | Authenticated via OAuth2 | The details of the auth attempt. | | Protocol | HTTP/1.0 | The request protocol. | +| RequestID | 00010203-0405-4607-8809-0a0b0c0d0e0f | The request ID pulled from the `--request-id-header`. Random UUID if empty | | RequestMethod | GET | The request method. | | Timestamp | 19/Mar/2015:17:20:19 -0400 | The date and time of the logging event. | | UserAgent | - | The full user agent as reported by the requesting client. | | Username | username@email.com | The email or username of the auth request. | | Status | AuthSuccess | The status of the auth request. See above for details. | -| Message | Authenticated via OAuth2 | The details of the auth attempt. | ### Request Log Format HTTP request logs will output by default in the below format: ``` - - [19/Mar/2015:17:20:19 -0400] GET "/path/" HTTP/1.1 "" + - - [19/Mar/2015:17:20:19 -0400] GET "/path/" HTTP/1.1 "" ``` If you require a different format than that, you can configure it with the `--request-logging-format` flag. The default format is configured as follows: ``` -{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}} +{{.Client}} - {{.RequestID}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}} ``` Available variables for request logging: @@ -236,6 +238,7 @@ Available variables for request logging: | Host | domain.com | The value of the Host header. | | Protocol | HTTP/1.0 | The request protocol. | | RequestDuration | 0.001 | The time in seconds that a request took to process. | +| RequestID | 00010203-0405-4607-8809-0a0b0c0d0e0f | The request ID pulled from the `--request-id-header`. Random UUID if empty | | RequestMethod | GET | The request method. | | RequestURI | "/oauth2/auth" | The URI path of the request. | | ResponseSize | 12 | The size in bytes of the response. | diff --git a/go.mod b/go.mod index b6ce05cd..9cb43c08 100644 --- a/go.mod +++ b/go.mod @@ -13,6 +13,7 @@ require ( github.com/fsnotify/fsnotify v1.4.9 github.com/ghodss/yaml v1.0.1-0.20190212211648-25d852aebe32 github.com/go-redis/redis/v8 v8.2.3 + github.com/google/uuid v1.2.0 github.com/justinas/alice v1.2.0 github.com/mbland/hmacauth v0.0.0-20170912233209-44256dfd4bfa github.com/mitchellh/mapstructure v1.1.2 diff --git a/go.sum b/go.sum index 0b129b72..0c506971 100644 --- a/go.sum +++ b/go.sum @@ -39,7 +39,6 @@ github.com/aws/aws-lambda-go v1.13.3/go.mod h1:4UKl9IzQMoD+QF79YdCuzCwp8VbmG4VAQ github.com/aws/aws-sdk-go v1.27.0/go.mod h1:KmX6BPdI08NWTb3/sm4ZGu5ShLoqVDhKgpiN924inxo= github.com/aws/aws-sdk-go-v2 v0.18.0/go.mod h1:JWVYvqSMppoMJC0x5wdwiImzgXTI9FuZwxzkQq9wy+g= github.com/beorn7/perks v0.0.0-20180321164747-3a771d992973/go.mod h1:Dwedo/Wpr24TaqPxmxbtue+5NUziq4I4S80YR8gNf3Q= -github.com/beorn7/perks v1.0.0 h1:HWo1m869IqiPhD389kmkxeTalrjNbbJTC8LXupb+sl0= github.com/beorn7/perks v1.0.0/go.mod h1:KWe93zE9D1o94FZ5RNwFwVgaQK1VOXiVxmqh+CedLV8= github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM= github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw= @@ -103,7 +102,6 @@ github.com/fsnotify/fsnotify v1.4.7/go.mod h1:jwhsz4b93w/PPRr/qN1Yymfu8t87LnFCMo github.com/fsnotify/fsnotify v1.4.9 h1:hsms1Qyu0jgnwNXIxa+/V/PDsU6CfLf6CNO8H7IWoS4= github.com/fsnotify/fsnotify v1.4.9/go.mod h1:znqG4EE+3YCdAaPaxE2ZRY/06pZUdp0tY4IgpuI1SZQ= github.com/ghodss/yaml v0.0.0-20150909031657-73d445a93680/go.mod h1:4dBDuWmgqj2HViK6kFavaiC9ZROes6MMH2rRYeMEF04= -github.com/ghodss/yaml v1.0.0 h1:wQHKEahhL6wmXdzwWG11gIVCkOv05bNOh+Rxn0yngAk= github.com/ghodss/yaml v1.0.0/go.mod h1:4dBDuWmgqj2HViK6kFavaiC9ZROes6MMH2rRYeMEF04= github.com/ghodss/yaml v1.0.1-0.20190212211648-25d852aebe32 h1:Mn26/9ZMNWSw9C9ERFA1PUxfmGpolnw2v0bKOREu5ew= github.com/ghodss/yaml v1.0.1-0.20190212211648-25d852aebe32/go.mod h1:GIjDIg/heH5DOkXY3YJ/wNhfHsQHoXGjl8G8amsYQ1I= @@ -149,7 +147,6 @@ github.com/golang/protobuf v1.4.0-rc.2/go.mod h1:LlEzMj4AhA7rCAGe4KMBDvJI+AwstrU github.com/golang/protobuf v1.4.0-rc.4.0.20200313231945-b860323f09d0/go.mod h1:WU3c8KckQ9AFe+yFwt9sWVRKCVIyN9cPHBJSNnbL67w= github.com/golang/protobuf v1.4.0/go.mod h1:jodUvKwWbYaEsadDk5Fwe5c77LiNKVO9IDvqG2KuDX0= github.com/golang/protobuf v1.4.1/go.mod h1:U8fpvMrcmy5pZrNK1lt4xCsGvpyWQ/VVv6QDs8UjoX8= -github.com/golang/protobuf v1.4.2 h1:+Z5KGCizgyZCbGh1KZqA0fcLLkwbsjIzS4aV2v7wJX0= github.com/golang/protobuf v1.4.2/go.mod h1:oDoupMAO8OvCJWAcko0GGGIgR6R6ocIYbsSw735rRwI= github.com/golang/protobuf v1.4.3 h1:JjCZWpVbqXDqFVmTfYWEVTMIYrL/NPdPSCHPJ0T/raM= github.com/golang/protobuf v1.4.3/go.mod h1:oDoupMAO8OvCJWAcko0GGGIgR6R6ocIYbsSw735rRwI= @@ -171,8 +168,9 @@ github.com/google/martian v2.1.0+incompatible/go.mod h1:9I4somxYTbIHy5NJKHRl3wXi github.com/google/pprof v0.0.0-20181206194817-3ea8567a2e57/go.mod h1:zfwlbNMJ+OItoe0UupaVj+oy1omPYYDuagoSzA8v9mc= github.com/google/renameio v0.1.0/go.mod h1:KWCgfxg9yswjAJkECMjeO8J8rahYeXnNhOm40UhjYkI= github.com/google/uuid v1.0.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= -github.com/google/uuid v1.1.1 h1:Gkbcsh/GbpXz7lPftLA3P6TYMwjCLYm83jiFQZF/3gY= github.com/google/uuid v1.1.1/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= +github.com/google/uuid v1.2.0 h1:qJYtXnJRWmpe7m/3XlyhrsLrEURqHRM2kxzoxXqyUDs= +github.com/google/uuid v1.2.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= github.com/googleapis/gax-go/v2 v2.0.4/go.mod h1:0Wqv26UfaUD9n4G6kQubkQ+KchISgw+vpHVxEJEs9eg= github.com/googleapis/gax-go/v2 v2.0.5 h1:sjZBwGj9Jlw33ImPtvFviGYvseOtDM7hkSKB7+Tv3SM= github.com/googleapis/gax-go/v2 v2.0.5/go.mod h1:DWXyrwAJ9X0FpwwEdw+IPEYBICEFu5mhpdKc/us6bOk= @@ -204,7 +202,6 @@ github.com/hashicorp/go-uuid v1.0.1/go.mod h1:6SBZvOh/SIDV7/2o3Jml5SYk/TvGqwFJ/b github.com/hashicorp/go-version v1.2.0/go.mod h1:fltr4n8CU8Ke44wwGCBoEymUuxUHl09ZGVZPK5anwXA= github.com/hashicorp/go.net v0.0.1/go.mod h1:hjKkEWcCURg++eb33jQU7oqQcI9XDCnUzHA0oac0k90= github.com/hashicorp/golang-lru v0.5.0/go.mod h1:/m3WP610KZHVQ1SGc6re/UDhFvYD7pJ4Ao+sR/qLZy8= -github.com/hashicorp/golang-lru v0.5.1 h1:0hERBMJE1eitiLkihrMvRVBYAkpHzc/J3QdDN+dAcgU= github.com/hashicorp/golang-lru v0.5.1/go.mod h1:/m3WP610KZHVQ1SGc6re/UDhFvYD7pJ4Ao+sR/qLZy8= github.com/hashicorp/hcl v1.0.0 h1:0Anlzjpi4vEasTeNFn2mLJgTSwt0+6sfsiTG8qcWGx4= github.com/hashicorp/hcl v1.0.0/go.mod h1:E5yfLk+7swimpb2L/Alb/PJmXilQ/rhwaUYs4T20WEQ= @@ -335,7 +332,6 @@ github.com/pquerna/cachecontrol v0.0.0-20180517163645-1555304b9b35 h1:J9b7z+QKAm github.com/pquerna/cachecontrol v0.0.0-20180517163645-1555304b9b35/go.mod h1:prYjPmNq4d1NPVmpShWobRqXY3q7Vp+80DqgxxUrUIA= github.com/prometheus/client_golang v0.9.1/go.mod h1:7SWBe2y4D6OKWSNQJUaRYU/AaXPKyh/dDVn+NZz0KFw= github.com/prometheus/client_golang v0.9.3-0.20190127221311-3c4408c8b829/go.mod h1:p2iRAGwDERtqlqzRXnrOVns+ignqQo//hLXqYxZYVNs= -github.com/prometheus/client_golang v0.9.3 h1:9iH4JKXLzFbOAdtqv/a+j8aewx2Y8lAjAydhbaScPF8= github.com/prometheus/client_golang v0.9.3/go.mod h1:/TN21ttK/J9q6uSwhBd54HahCDft0ttaMvbicHlPoso= github.com/prometheus/client_golang v1.0.0/go.mod h1:db9x61etRT2tGnBNRi70OPL5FsnadC4Ky3P0J6CfImo= github.com/prometheus/client_golang v1.3.0/go.mod h1:hJaj2vgQTGQmVCsAACORcieXFeDPbaTKGT+JTgUa3og= @@ -345,14 +341,12 @@ github.com/prometheus/client_golang v1.9.0/go.mod h1:FqZLKOZnGdFAhOK4nqGHa7D66Id github.com/prometheus/client_model v0.0.0-20180712105110-5c3871d89910/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo= github.com/prometheus/client_model v0.0.0-20190115171406-56726106282f/go.mod h1:MbSGuTsp3dbXC40dX6PRTWyKYBIrTGTE9sqQNg2J8bo= github.com/prometheus/client_model v0.0.0-20190129233127-fd36f4220a90/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= -github.com/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4 h1:gQz4mCbXsO+nc9n1hCxHcGA3Zx3Eo+UHZoInFGUIXNM= github.com/prometheus/client_model v0.0.0-20190812154241-14fe0d1b01d4/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= github.com/prometheus/client_model v0.1.0/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= github.com/prometheus/client_model v0.2.0 h1:uq5h0d+GuxiXLJLNABMgp2qUWDPiLvgCzz2dUR+/W/M= github.com/prometheus/client_model v0.2.0/go.mod h1:xMI15A0UPsDsEKsMN9yxemIoYk6Tm2C1GtYGdfGttqA= github.com/prometheus/common v0.0.0-20181113130724-41aa239b4cce/go.mod h1:daVV7qP5qjZbuso7PdcryaAu0sAZbrN9i7WWcTMWvro= github.com/prometheus/common v0.2.0/go.mod h1:TNfzLD0ON7rHzMJeJkieUDPYmFC7Snx/y86RQel1bk4= -github.com/prometheus/common v0.4.0 h1:7etb9YClo3a6HjLzfl6rIQaU+FDfi0VSX39io3aQ+DM= github.com/prometheus/common v0.4.0/go.mod h1:TNfzLD0ON7rHzMJeJkieUDPYmFC7Snx/y86RQel1bk4= github.com/prometheus/common v0.4.1/go.mod h1:TNfzLD0ON7rHzMJeJkieUDPYmFC7Snx/y86RQel1bk4= github.com/prometheus/common v0.7.0/go.mod h1:DjGbpBbp5NYNiECxcL/VnbXCCaQpKd3tt26CguLLsqA= @@ -361,7 +355,6 @@ github.com/prometheus/common v0.15.0 h1:4fgOnadei3EZvgRwxJ7RMpG1k1pOZth5Pc13tysp github.com/prometheus/common v0.15.0/go.mod h1:U+gB1OBLb1lF3O42bTCL+FK18tX9Oar16Clt/msog/s= github.com/prometheus/procfs v0.0.0-20181005140218-185b4288413d/go.mod h1:c3At6R/oaqEKCNdg8wHV1ftS6bRYblBhIjjI8uT2IGk= github.com/prometheus/procfs v0.0.0-20190117184657-bf6a532e95b1/go.mod h1:c3At6R/oaqEKCNdg8wHV1ftS6bRYblBhIjjI8uT2IGk= -github.com/prometheus/procfs v0.0.0-20190507164030-5867b95ac084 h1:sofwID9zm4tzrgykg80hfFph1mryUeLRsUfoocVVmRY= github.com/prometheus/procfs v0.0.0-20190507164030-5867b95ac084/go.mod h1:TjEm7ze935MbeOT/UhFTIMYKhuLP4wbCsTZCD3I8kEA= github.com/prometheus/procfs v0.0.2/go.mod h1:TjEm7ze935MbeOT/UhFTIMYKhuLP4wbCsTZCD3I8kEA= github.com/prometheus/procfs v0.0.8/go.mod h1:7Qr8sr6344vo1JqZ6HhLceV9o3AJ1Ff+GxbHq6oeK9A= @@ -396,7 +389,6 @@ github.com/spf13/jwalterweatherman v1.0.0 h1:XHEdyB+EcvlqZamSM4ZOMGlc93t6AcsBEu9 github.com/spf13/jwalterweatherman v1.0.0/go.mod h1:cQK4TGJAtQXfYWX+Ddv3mKDzgVb68N+wFjFa4jdeBTo= github.com/spf13/pflag v0.0.0-20170130214245-9ff6c6923cff/go.mod h1:DYY7MBk1bdzusC3SYhjObp+wFpr4gzcvqqNjLnInEg4= github.com/spf13/pflag v1.0.1/go.mod h1:DYY7MBk1bdzusC3SYhjObp+wFpr4gzcvqqNjLnInEg4= -github.com/spf13/pflag v1.0.3 h1:zPAT6CGy6wXeQ7NtTnaTerfKOsV6V6F8agHXFiazDkg= github.com/spf13/pflag v1.0.3/go.mod h1:DYY7MBk1bdzusC3SYhjObp+wFpr4gzcvqqNjLnInEg4= github.com/spf13/pflag v1.0.5 h1:iy+VFUOCP1a+8yFto/drg2CJ5u0yRoB7fZw3DKv/JXA= github.com/spf13/pflag v1.0.5/go.mod h1:McXfInJRrz4CZXVZOBLb0bTZqETkiAhM9Iw0y3An2Bg= @@ -437,7 +429,6 @@ go.etcd.io/bbolt v1.3.3/go.mod h1:IbVyRI1SCnLcuJnV2u8VeU0CEYM7e686BmAb1XKL+uU= go.etcd.io/etcd v0.0.0-20191023171146-3cf2f69b5738/go.mod h1:dnLIgRNXwCJa5e+c6mIZCrds/GIG4ncV9HhK5PX7jPg= go.opencensus.io v0.20.1/go.mod h1:6WKK9ahsWS3RSO+PY9ZHZUfv2irvY6gN279GOPZjmmk= go.opencensus.io v0.20.2/go.mod h1:6WKK9ahsWS3RSO+PY9ZHZUfv2irvY6gN279GOPZjmmk= -go.opencensus.io v0.21.0 h1:mU6zScU4U1YAFPHEHYk+3JC4SY7JxgkqS10ZOSyksNg= go.opencensus.io v0.21.0/go.mod h1:mSImk1erAIZhrmZN+AvHh14ztQfjbGwt4TtuofqLduU= go.opencensus.io v0.22.2 h1:75k/FF0Q2YM8QYo07VPddOLBslDt1MZOdEslOHvmzAs= go.opencensus.io v0.22.2/go.mod h1:yxeiOL68Rb0Xd1ddK5vPZ/oVn4vY4Ynel7k9FzqtOIw= @@ -453,7 +444,6 @@ go.uber.org/zap v1.10.0/go.mod h1:vwi/ZaCAaUcBkycHslxD9B2zi4UTXhF60s6SWpuDF0Q= go.uber.org/zap v1.13.0/go.mod h1:zwrFLgMcdUuIBviXEYEH1YKNaOBnKXsx2IPda5bBwHM= golang.org/x/crypto v0.0.0-20180904163835-0709b304e793/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= golang.org/x/crypto v0.0.0-20181029021203-45a5f77698d3/go.mod h1:6SG95UA2DQfeDnfUPMdvaQW0Q7yPrPDi9nlGo2tz2b4= -golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2 h1:VklqNMn3ovrHsnt90PveolxSbWFaJdECFbxSq0Mqo2M= golang.org/x/crypto v0.0.0-20190308221718-c2843e01d9a2/go.mod h1:djNgcEr1/C05ACkg1iLfiJU5Ep61QUkGW8qpdssI0+w= golang.org/x/crypto v0.0.0-20190510104115-cbcb75029529/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= golang.org/x/crypto v0.0.0-20190701094942-4def268fd1a4/go.mod h1:yigFU9vqHzYiE8UmvKecakEJjdnWj3jj499lnFckfCI= @@ -506,7 +496,6 @@ golang.org/x/sync v0.0.0-20181108010431-42b317875d0f/go.mod h1:RxMgew5VJxzue5/jJ golang.org/x/sync v0.0.0-20181221193216-37e7f081c4d4/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.0.0-20190227155943-e225da77a7e6/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.0.0-20190423024810-112230192c58/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= -golang.org/x/sync v0.0.0-20190911185100-cd5d95a43a6e h1:vcxGaoTs7kV8m5Np9uUNQin4BrLOthgV7252N8V+FwY= golang.org/x/sync v0.0.0-20190911185100-cd5d95a43a6e/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= golang.org/x/sync v0.0.0-20201207232520-09787c993a3a h1:DcqTD9SDLc+1P/r1EmRBwnVsrOwW+kk2vWf9n+1sGhs= golang.org/x/sync v0.0.0-20201207232520-09787c993a3a/go.mod h1:RxMgew5VJxzue5/jJTE5uejpjVlOe/izrB70Jof72aM= diff --git a/oauthproxy.go b/oauthproxy.go index f1bd9a62..588d827a 100644 --- a/oauthproxy.go +++ b/oauthproxy.go @@ -289,7 +289,7 @@ func (p *OAuthProxy) setupServer(opts *options.Options) error { // the OAuth2 Proxy authentication logic kicks in. // For example forcing HTTPS or health checks. func buildPreAuthChain(opts *options.Options) (alice.Chain, error) { - chain := alice.New(middleware.NewScope(opts.ReverseProxy)) + chain := alice.New(middleware.NewScope(opts.ReverseProxy, opts.Logging.RequestIDHeader)) if opts.ForceHTTPS { _, httpsPort, err := net.SplitHostPort(opts.Server.SecureBindAddress) @@ -596,7 +596,14 @@ func (p *OAuthProxy) ErrorPage(rw http.ResponseWriter, req *http.Request, code i redirectURL = "/" } - p.pageWriter.WriteErrorPage(rw, code, redirectURL, appError, messages...) + scope := middlewareapi.GetRequestScope(req) + p.pageWriter.WriteErrorPage(rw, pagewriter.ErrorPageOpts{ + Status: code, + RedirectURL: redirectURL, + RequestID: scope.RequestID, + AppError: appError, + Messages: messages, + }) } // IsAllowedRequest is used to check if auth should be skipped for this request @@ -657,7 +664,7 @@ func (p *OAuthProxy) SignInPage(rw http.ResponseWriter, req *http.Request, code redirectURL = "/" } - p.pageWriter.WriteSignInPage(rw, redirectURL) + p.pageWriter.WriteSignInPage(rw, req, redirectURL) } // ManualSignIn handles basic auth logins to the proxy diff --git a/pkg/apis/middleware/scope.go b/pkg/apis/middleware/scope.go index b3693cc6..2d84f00e 100644 --- a/pkg/apis/middleware/scope.go +++ b/pkg/apis/middleware/scope.go @@ -21,6 +21,10 @@ type RequestScope struct { // mode and if request `X-Forwarded-*` headers should be trusted ReverseProxy bool + // RequestID is set to the request's `X-Request-Id` header if set. + // Otherwise a random UUID is set. + RequestID string + // Session details the authenticated users information (if it exists). Session *sessions.SessionState diff --git a/pkg/apis/options/logging.go b/pkg/apis/options/logging.go index 1c6f9415..3ed79127 100644 --- a/pkg/apis/options/logging.go +++ b/pkg/apis/options/logging.go @@ -17,6 +17,7 @@ type Logging struct { ExcludePaths []string `flag:"exclude-logging-path" cfg:"exclude_logging_paths"` LocalTime bool `flag:"logging-local-time" cfg:"logging_local_time"` SilencePing bool `flag:"silence-ping-logging" cfg:"silence_ping_logging"` + RequestIDHeader string `flag:"request-id-header" cfg:"request_id_header"` File LogFileOptions `cfg:",squash"` } @@ -43,6 +44,7 @@ func loggingFlagSet() *pflag.FlagSet { flagSet.StringSlice("exclude-logging-path", []string{}, "Exclude logging requests to paths (eg: '/path1,/path2,/path3')") flagSet.Bool("logging-local-time", true, "If the time in log files and backup filenames are local or UTC time") flagSet.Bool("silence-ping-logging", false, "Disable logging of requests to ping endpoint") + flagSet.String("request-id-header", "X-Request-Id", "Request header to use as the request ID") flagSet.String("logging-filename", "", "File to log requests to, empty for stdout") flagSet.Int("logging-max-size", 100, "Maximum size in megabytes of the log file before rotation") @@ -59,6 +61,7 @@ func loggingDefaults() Logging { ExcludePaths: nil, LocalTime: true, SilencePing: false, + RequestIDHeader: "X-Request-Id", AuthEnabled: true, AuthFormat: logger.DefaultAuthLoggingFormat, RequestEnabled: true, diff --git a/pkg/app/pagewriter/error.html b/pkg/app/pagewriter/error.html index 56306227..a346b2b3 100644 --- a/pkg/app/pagewriter/error.html +++ b/pkg/app/pagewriter/error.html @@ -47,7 +47,7 @@

{{.Title}}

- {{ if .Message }} + {{ if or .Message .RequestID }}

More Info

@@ -56,9 +56,16 @@
{{ end }} diff --git a/pkg/app/pagewriter/error_page.go b/pkg/app/pagewriter/error_page.go index 28d81bb1..831eeb3a 100644 --- a/pkg/app/pagewriter/error_page.go +++ b/pkg/app/pagewriter/error_page.go @@ -5,6 +5,7 @@ import ( "html/template" "net/http" + middlewareapi "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/apis/middleware" "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/logger" ) @@ -37,11 +38,25 @@ type errorPageWriter struct { debug bool } +// ErrorPageOpts bundles up all the content needed to write the Error Page +type ErrorPageOpts struct { + // HTTP status code + Status int + // Redirect URL for "Go back" and "Sign in" buttons + RedirectURL string + // The UUID of the request + RequestID string + // App Error shown in debug mode + AppError string + // Generic error messages shown in non-debug mode + Messages []interface{} +} + // WriteErrorPage writes an error page to the given response writer. // It uses the passed redirectURL to give users the option to go back to where // they originally came from or try signing in again. -func (e *errorPageWriter) WriteErrorPage(rw http.ResponseWriter, status int, redirectURL string, appError string, messages ...interface{}) { - rw.WriteHeader(status) +func (e *errorPageWriter) WriteErrorPage(rw http.ResponseWriter, opts ErrorPageOpts) { + rw.WriteHeader(opts.Status) // We allow unescaped template.HTML since it is user configured options /* #nosec G203 */ @@ -51,14 +66,16 @@ func (e *errorPageWriter) WriteErrorPage(rw http.ResponseWriter, status int, red ProxyPrefix string StatusCode int Redirect string + RequestID string Footer template.HTML Version string }{ - Title: http.StatusText(status), - Message: e.getMessage(status, appError, messages...), + Title: http.StatusText(opts.Status), + Message: e.getMessage(opts.Status, opts.AppError, opts.Messages...), ProxyPrefix: e.proxyPrefix, - StatusCode: status, - Redirect: redirectURL, + StatusCode: opts.Status, + Redirect: opts.RedirectURL, + RequestID: opts.RequestID, Footer: template.HTML(e.footer), Version: e.version, } @@ -74,7 +91,14 @@ func (e *errorPageWriter) WriteErrorPage(rw http.ResponseWriter, status int, red // It is expected to always render a bad gateway error. func (e *errorPageWriter) ProxyErrorHandler(rw http.ResponseWriter, req *http.Request, proxyErr error) { logger.Errorf("Error proxying to upstream server: %v", proxyErr) - e.WriteErrorPage(rw, http.StatusBadGateway, "", proxyErr.Error(), "There was a problem connecting to the upstream server.") + scope := middlewareapi.GetRequestScope(req) + e.WriteErrorPage(rw, ErrorPageOpts{ + Status: http.StatusBadGateway, + RedirectURL: "", // The user is already logged in and has hit an upstream error. Makes no sense to redirect in this case. + RequestID: scope.RequestID, + AppError: proxyErr.Error(), + Messages: []interface{}{"There was a problem connecting to the upstream server."}, + }) } // getMessage creates the message for the template parameters. diff --git a/pkg/app/pagewriter/error_page_test.go b/pkg/app/pagewriter/error_page_test.go index 56cd821b..f8e3bfb7 100644 --- a/pkg/app/pagewriter/error_page_test.go +++ b/pkg/app/pagewriter/error_page_test.go @@ -6,6 +6,7 @@ import ( "io/ioutil" "net/http/httptest" + middlewareapi "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/apis/middleware" . "github.com/onsi/ginkgo" . "github.com/onsi/gomega" ) @@ -14,7 +15,7 @@ var _ = Describe("Error Page Writer", func() { var errorPage *errorPageWriter BeforeEach(func() { - tmpl, err := template.New("").Parse("{{.Title}} {{.Message}} {{.ProxyPrefix}} {{.StatusCode}} {{.Redirect}} {{.Footer}} {{.Version}}") + tmpl, err := template.New("").Parse("{{.Title}} {{.Message}} {{.ProxyPrefix}} {{.StatusCode}} {{.Redirect}} {{.RequestID}} {{.Footer}} {{.Version}}") Expect(err).ToNot(HaveOccurred()) errorPage = &errorPageWriter{ @@ -28,41 +29,77 @@ var _ = Describe("Error Page Writer", func() { Context("WriteErrorPage", func() { It("Writes the template to the response writer", func() { recorder := httptest.NewRecorder() - errorPage.WriteErrorPage(recorder, 403, "/redirect", "Access Denied") + errorPage.WriteErrorPage(recorder, ErrorPageOpts{ + Status: 403, + RedirectURL: "/redirect", + RequestID: testRequestID, + AppError: "Access Denied", + }) body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) - Expect(string(body)).To(Equal("Forbidden You do not have permission to access this resource. /prefix/ 403 /redirect Custom Footer Text v0.0.0-test")) + Expect(string(body)).To(Equal("Forbidden You do not have permission to access this resource. /prefix/ 403 /redirect 11111111-2222-4333-8444-555555555555 Custom Footer Text v0.0.0-test")) }) It("With a different code, uses the stock message for the correct code", func() { recorder := httptest.NewRecorder() - errorPage.WriteErrorPage(recorder, 500, "/redirect", "Access Denied") + errorPage.WriteErrorPage(recorder, ErrorPageOpts{ + Status: 500, + RedirectURL: "/redirect", + RequestID: testRequestID, + AppError: "Access Denied", + }) body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) - Expect(string(body)).To(Equal("Internal Server Error Oops! Something went wrong. For more information contact your server administrator. /prefix/ 500 /redirect Custom Footer Text v0.0.0-test")) + Expect(string(body)).To(Equal("Internal Server Error Oops! Something went wrong. For more information contact your server administrator. /prefix/ 500 /redirect 11111111-2222-4333-8444-555555555555 Custom Footer Text v0.0.0-test")) }) It("With a message override, uses the message", func() { recorder := httptest.NewRecorder() - errorPage.WriteErrorPage(recorder, 403, "/redirect", "Access Denied", "An extra message: %s", "with more context.") + errorPage.WriteErrorPage(recorder, ErrorPageOpts{ + Status: 403, + RedirectURL: "/redirect", + RequestID: testRequestID, + AppError: "Access Denied", + Messages: []interface{}{ + "An extra message: %s", + "with more context.", + }, + }) body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) - Expect(string(body)).To(Equal("Forbidden An extra message: with more context. /prefix/ 403 /redirect Custom Footer Text v0.0.0-test")) + Expect(string(body)).To(Equal("Forbidden An extra message: with more context. /prefix/ 403 /redirect 11111111-2222-4333-8444-555555555555 Custom Footer Text v0.0.0-test")) + }) + + It("Sanitizes malicious user input", func() { + recorder := httptest.NewRecorder() + errorPage.WriteErrorPage(recorder, ErrorPageOpts{ + Status: 403, + RedirectURL: "/redirect", + RequestID: "", + AppError: "Access Denied", + }) + + body, err := ioutil.ReadAll(recorder.Result().Body) + Expect(err).ToNot(HaveOccurred()) + Expect(string(body)).To(Equal("Forbidden You do not have permission to access this resource. /prefix/ 403 /redirect <script>alert(1)</script> Custom Footer Text v0.0.0-test")) }) }) Context("ProxyErrorHandler", func() { It("Writes a bad gateway error the response writer", func() { req := httptest.NewRequest("", "/bad-gateway", nil) + req = middlewareapi.AddRequestScope(req, &middlewareapi.RequestScope{ + RequestID: testRequestID, + }) recorder := httptest.NewRecorder() errorPage.ProxyErrorHandler(recorder, req, errors.New("some upstream error")) body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) - Expect(string(body)).To(Equal("Bad Gateway There was a problem connecting to the upstream server. /prefix/ 502 Custom Footer Text v0.0.0-test")) + Expect(string(body)).To(Equal("Bad Gateway There was a problem connecting to the upstream server. /prefix/ 502 11111111-2222-4333-8444-555555555555 Custom Footer Text v0.0.0-test")) }) }) @@ -78,7 +115,11 @@ var _ = Describe("Error Page Writer", func() { Context("WriteErrorPage", func() { It("Writes the detailed error in place of the message", func() { recorder := httptest.NewRecorder() - errorPage.WriteErrorPage(recorder, 403, "/redirect", "Debug error") + errorPage.WriteErrorPage(recorder, ErrorPageOpts{ + Status: 403, + RedirectURL: "/redirect", + AppError: "Debug error", + }) body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) @@ -89,6 +130,9 @@ var _ = Describe("Error Page Writer", func() { Context("ProxyErrorHandler", func() { It("Writes a bad gateway error the response writer", func() { req := httptest.NewRequest("", "/bad-gateway", nil) + req = middlewareapi.AddRequestScope(req, &middlewareapi.RequestScope{ + RequestID: testRequestID, + }) recorder := httptest.NewRecorder() errorPage.ProxyErrorHandler(recorder, req, errors.New("some upstream error")) diff --git a/pkg/app/pagewriter/pagewriter.go b/pkg/app/pagewriter/pagewriter.go index ad79aee2..3b7104b2 100644 --- a/pkg/app/pagewriter/pagewriter.go +++ b/pkg/app/pagewriter/pagewriter.go @@ -10,8 +10,8 @@ import ( // It can also be used to write errors for the http.ReverseProxy used in the // upstream package. type Writer interface { - WriteSignInPage(rw http.ResponseWriter, redirectURL string) - WriteErrorPage(rw http.ResponseWriter, status int, redirectURL string, appError string, messages ...interface{}) + WriteSignInPage(rw http.ResponseWriter, req *http.Request, redirectURL string) + WriteErrorPage(rw http.ResponseWriter, opts ErrorPageOpts) ProxyErrorHandler(rw http.ResponseWriter, req *http.Request, proxyErr error) } diff --git a/pkg/app/pagewriter/pagewriter_suite_test.go b/pkg/app/pagewriter/pagewriter_suite_test.go index ade6a94b..e27eee68 100644 --- a/pkg/app/pagewriter/pagewriter_suite_test.go +++ b/pkg/app/pagewriter/pagewriter_suite_test.go @@ -8,6 +8,8 @@ import ( . "github.com/onsi/gomega" ) +const testRequestID = "11111111-2222-4333-8444-555555555555" + func TestOptionsSuite(t *testing.T) { logger.SetOutput(GinkgoWriter) logger.SetErrOutput(GinkgoWriter) diff --git a/pkg/app/pagewriter/pagewriter_test.go b/pkg/app/pagewriter/pagewriter_test.go index 3d7669f9..eefd2437 100644 --- a/pkg/app/pagewriter/pagewriter_test.go +++ b/pkg/app/pagewriter/pagewriter_test.go @@ -2,6 +2,7 @@ package pagewriter import ( "io/ioutil" + "net/http" "net/http/httptest" "os" "path/filepath" @@ -14,6 +15,7 @@ var _ = Describe("Writer", func() { Context("NewWriter", func() { var writer Writer var opts Opts + var request *http.Request BeforeEach(func() { opts = Opts{ @@ -26,6 +28,8 @@ var _ = Describe("Writer", func() { ProviderName: "", SignInMessage: "", } + + request = httptest.NewRequest("", "http://127.0.0.1/", nil) }) Context("With no custom templates", func() { @@ -37,7 +41,11 @@ var _ = Describe("Writer", func() { It("Writes the default error template", func() { recorder := httptest.NewRecorder() - writer.WriteErrorPage(recorder, 500, "/redirect", "Some debug error") + writer.WriteErrorPage(recorder, ErrorPageOpts{ + Status: 500, + RedirectURL: "/redirect", + AppError: "Some debug error", + }) body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) @@ -46,7 +54,7 @@ var _ = Describe("Writer", func() { It("Writes the default sign in template", func() { recorder := httptest.NewRecorder() - writer.WriteSignInPage(recorder, "/redirect") + writer.WriteSignInPage(recorder, request, "/redirect") body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) @@ -80,7 +88,11 @@ var _ = Describe("Writer", func() { It("Writes the custom error template", func() { recorder := httptest.NewRecorder() - writer.WriteErrorPage(recorder, 500, "/redirect", "Some debug error") + writer.WriteErrorPage(recorder, ErrorPageOpts{ + Status: 500, + RedirectURL: "/redirect", + AppError: "Some debug error", + }) body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) @@ -89,7 +101,7 @@ var _ = Describe("Writer", func() { It("Writes the custom sign in template", func() { recorder := httptest.NewRecorder() - writer.WriteSignInPage(recorder, "/redirect") + writer.WriteSignInPage(recorder, request, "/redirect") body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) diff --git a/pkg/app/pagewriter/sign_in_page.go b/pkg/app/pagewriter/sign_in_page.go index 43f84576..a8eb4054 100644 --- a/pkg/app/pagewriter/sign_in_page.go +++ b/pkg/app/pagewriter/sign_in_page.go @@ -13,6 +13,7 @@ import ( "html/template" "net/http" + middlewareapi "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/apis/middleware" "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/logger" ) @@ -53,7 +54,7 @@ type signInPageWriter struct { // WriteSignInPage writes the sign-in page to the given response writer. // It uses the redirectURL to be able to set the final destination for the user post login. -func (s *signInPageWriter) WriteSignInPage(rw http.ResponseWriter, redirectURL string) { +func (s *signInPageWriter) WriteSignInPage(rw http.ResponseWriter, req *http.Request, redirectURL string) { // We allow unescaped template.HTML since it is user configured options /* #nosec G203 */ t := struct { @@ -79,7 +80,13 @@ func (s *signInPageWriter) WriteSignInPage(rw http.ResponseWriter, redirectURL s err := s.template.Execute(rw, t) if err != nil { logger.Printf("Error rendering sign-in template: %v", err) - s.errorPageWriter.WriteErrorPage(rw, http.StatusInternalServerError, redirectURL, err.Error()) + scope := middlewareapi.GetRequestScope(req) + s.errorPageWriter.WriteErrorPage(rw, ErrorPageOpts{ + Status: http.StatusInternalServerError, + RedirectURL: redirectURL, + RequestID: scope.RequestID, + AppError: err.Error(), + }) } } diff --git a/pkg/app/pagewriter/sign_in_page_test.go b/pkg/app/pagewriter/sign_in_page_test.go index d32c93be..2ea1d429 100644 --- a/pkg/app/pagewriter/sign_in_page_test.go +++ b/pkg/app/pagewriter/sign_in_page_test.go @@ -5,11 +5,13 @@ import ( "fmt" "html/template" "io/ioutil" + "net/http" "net/http/httptest" "os" "path/filepath" "strings" + middlewareapi "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/apis/middleware" . "github.com/onsi/ginkgo" . "github.com/onsi/ginkgo/extensions/table" . "github.com/onsi/gomega" @@ -18,10 +20,11 @@ import ( var _ = Describe("SignIn Page", func() { Context("SignIn Page Writer", func() { + var request *http.Request var signInPage *signInPageWriter BeforeEach(func() { - errorTmpl, err := template.New("").Parse("{{.Title}}") + errorTmpl, err := template.New("").Parse("{{.Title}} | {{.RequestID}}") Expect(err).ToNot(HaveOccurred()) errorPage := &errorPageWriter{ template: errorTmpl, @@ -41,12 +44,17 @@ var _ = Describe("SignIn Page", func() { displayLoginForm: true, logoData: "Logo Data", } + + request = httptest.NewRequest("", "http://127.0.0.1/", nil) + request = middlewareapi.AddRequestScope(request, &middlewareapi.RequestScope{ + RequestID: testRequestID, + }) }) Context("WriteSignInPage", func() { It("Writes the template to the response writer", func() { recorder := httptest.NewRecorder() - signInPage.WriteSignInPage(recorder, "/redirect") + signInPage.WriteSignInPage(recorder, request, "/redirect") body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) @@ -60,11 +68,11 @@ var _ = Describe("SignIn Page", func() { signInPage.template = tmpl recorder := httptest.NewRecorder() - signInPage.WriteSignInPage(recorder, "/redirect") + signInPage.WriteSignInPage(recorder, request, "/redirect") body, err := ioutil.ReadAll(recorder.Result().Body) Expect(err).ToNot(HaveOccurred()) - Expect(string(body)).To(Equal("Internal Server Error")) + Expect(string(body)).To(Equal(fmt.Sprintf("Internal Server Error | %s", testRequestID))) }) }) }) diff --git a/pkg/app/pagewriter/templates_test.go b/pkg/app/pagewriter/templates_test.go index afa6294f..cfcbcfca 100644 --- a/pkg/app/pagewriter/templates_test.go +++ b/pkg/app/pagewriter/templates_test.go @@ -51,6 +51,7 @@ var _ = Describe("Templates", func() { StatusCode int Title string Message string + RequestID string // For custom templates TestString string @@ -67,6 +68,7 @@ var _ = Describe("Templates", func() { StatusCode: 404, Title: "", Message: "<message>", + RequestID: "<request-id>", TestString: "Testing", } diff --git a/pkg/logger/logger.go b/pkg/logger/logger.go index 86ad720e..cb1da0a4 100644 --- a/pkg/logger/logger.go +++ b/pkg/logger/logger.go @@ -12,6 +12,7 @@ import ( "text/template" "time" + middlewareapi "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/apis/middleware" requestutil "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/requests/util" ) @@ -25,9 +26,9 @@ const ( // DefaultStandardLoggingFormat defines the default standard log format DefaultStandardLoggingFormat = "[{{.Timestamp}}] [{{.File}}] {{.Message}}" // DefaultAuthLoggingFormat defines the default auth log format - DefaultAuthLoggingFormat = "{{.Client}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}}" + DefaultAuthLoggingFormat = "{{.Client}} - {{.RequestID}} - {{.Username}} [{{.Timestamp}}] [{{.Status}}] {{.Message}}" // DefaultRequestLoggingFormat defines the default request log format - DefaultRequestLoggingFormat = "{{.Client}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}" + DefaultRequestLoggingFormat = "{{.Client}} - {{.RequestID}} - {{.Username}} [{{.Timestamp}}] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}" // AuthSuccess indicates that an auth attempt has succeeded explicitly AuthSuccess AuthStatus = "AuthSuccess" @@ -63,6 +64,7 @@ type authLogMessageData struct { Client, Host, Protocol, + RequestID, RequestMethod, Timestamp, UserAgent, @@ -75,6 +77,7 @@ type reqLogMessageData struct { Client, Host, Protocol, + RequestID, RequestDuration, RequestMethod, RequestURI, @@ -195,10 +198,12 @@ func (l *Logger) PrintAuthf(username string, req *http.Request, status AuthStatu l.mu.Lock() defer l.mu.Unlock() + scope := middlewareapi.GetRequestScope(req) err := l.authTemplate.Execute(l.writer, authLogMessageData{ Client: client, Host: requestutil.GetRequestHost(req), Protocol: req.Proto, + RequestID: scope.RequestID, RequestMethod: req.Method, Timestamp: FormatTimestamp(now), UserAgent: fmt.Sprintf("%q", req.UserAgent()), @@ -249,10 +254,12 @@ func (l *Logger) PrintReq(username, upstream string, req *http.Request, url url. l.mu.Lock() defer l.mu.Unlock() + scope := middlewareapi.GetRequestScope(req) err := l.reqTemplate.Execute(l.writer, reqLogMessageData{ Client: client, Host: requestutil.GetRequestHost(req), Protocol: req.Proto, + RequestID: scope.RequestID, RequestDuration: fmt.Sprintf("%0.3f", duration), RequestMethod: req.Method, RequestURI: fmt.Sprintf("%q", url.RequestURI()), diff --git a/pkg/middleware/request_logger_test.go b/pkg/middleware/request_logger_test.go index 0a1e35ff..5df64363 100644 --- a/pkg/middleware/request_logger_test.go +++ b/pkg/middleware/request_logger_test.go @@ -13,7 +13,7 @@ import ( . "github.com/onsi/gomega" ) -const RequestLoggingFormatWithoutTime = "{{.Client}} - {{.Username}} [TIMELESS] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}" +const RequestLoggingFormatWithoutTime = "{{.Client}} - {{.RequestID}} - {{.Username}} [TIMELESS] {{.Host}} {{.RequestMethod}} {{.Upstream}} {{.RequestURI}} {{.Protocol}} {{.UserAgent}} {{.StatusCode}} {{.ResponseSize}} {{.RequestDuration}}" var _ = Describe("Request logger suite", func() { type requestLoggerTableInput struct { @@ -37,7 +37,10 @@ var _ = Describe("Request logger suite", func() { req.RemoteAddr = "127.0.0.1" req.Host = "test-server" - scope := &middlewareapi.RequestScope{Session: in.Session} + scope := &middlewareapi.RequestScope{ + RequestID: "11111111-2222-4333-8444-555555555555", + Session: in.Session, + } req = middlewareapi.AddRequestScope(req, scope) handler := NewRequestLogger()(testUpstreamHandler(in.Upstream)) @@ -47,7 +50,7 @@ var _ = Describe("Request logger suite", func() { }, Entry("standard request", &requestLoggerTableInput{ Format: RequestLoggingFormatWithoutTime, - ExpectedLogMessage: "127.0.0.1 - standard.user [TIMELESS] test-server GET standard \"/foo/bar\" HTTP/1.1 \"\" 200 4 0.000\n", + ExpectedLogMessage: "127.0.0.1 - 11111111-2222-4333-8444-555555555555 - standard.user [TIMELESS] test-server GET standard \"/foo/bar\" HTTP/1.1 \"\" 200 4 0.000\n", Path: "/foo/bar", ExcludePaths: []string{}, Upstream: "standard", @@ -55,7 +58,7 @@ var _ = Describe("Request logger suite", func() { }), Entry("with unrelated path excluded", &requestLoggerTableInput{ Format: RequestLoggingFormatWithoutTime, - ExpectedLogMessage: "127.0.0.1 - unrelated.exclusion [TIMELESS] test-server GET unrelated \"/foo/bar\" HTTP/1.1 \"\" 200 4 0.000\n", + ExpectedLogMessage: "127.0.0.1 - 11111111-2222-4333-8444-555555555555 - unrelated.exclusion [TIMELESS] test-server GET unrelated \"/foo/bar\" HTTP/1.1 \"\" 200 4 0.000\n", Path: "/foo/bar", ExcludePaths: []string{"/ping"}, Upstream: "unrelated", @@ -69,7 +72,7 @@ var _ = Describe("Request logger suite", func() { }), Entry("ping path", &requestLoggerTableInput{ Format: RequestLoggingFormatWithoutTime, - ExpectedLogMessage: "127.0.0.1 - mr.ping [TIMELESS] test-server GET - \"/ping\" HTTP/1.1 \"\" 200 4 0.000\n", + ExpectedLogMessage: "127.0.0.1 - 11111111-2222-4333-8444-555555555555 - mr.ping [TIMELESS] test-server GET - \"/ping\" HTTP/1.1 \"\" 200 4 0.000\n", Path: "/ping", ExcludePaths: []string{}, Upstream: "", diff --git a/pkg/middleware/scope.go b/pkg/middleware/scope.go index 9218faa0..d0dd81ec 100644 --- a/pkg/middleware/scope.go +++ b/pkg/middleware/scope.go @@ -3,18 +3,31 @@ package middleware import ( "net/http" + "github.com/google/uuid" "github.com/justinas/alice" middlewareapi "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/apis/middleware" ) -func NewScope(reverseProxy bool) alice.Constructor { +func NewScope(reverseProxy bool, idHeader string) alice.Constructor { return func(next http.Handler) http.Handler { return http.HandlerFunc(func(rw http.ResponseWriter, req *http.Request) { scope := &middlewareapi.RequestScope{ ReverseProxy: reverseProxy, + RequestID: genRequestID(req, idHeader), } req = middlewareapi.AddRequestScope(req, scope) next.ServeHTTP(rw, req) }) } } + +// genRequestID sets a request-wide ID for use in logging or error pages. +// If a RequestID header is set, it uses that. Otherwise, it generates a random +// UUID for the lifespan of the request. +func genRequestID(req *http.Request, idHeader string) string { + rid := req.Header.Get(idHeader) + if rid != "" { + return rid + } + return uuid.New().String() +} diff --git a/pkg/middleware/scope_test.go b/pkg/middleware/scope_test.go index 3432d148..1a76132f 100644 --- a/pkg/middleware/scope_test.go +++ b/pkg/middleware/scope_test.go @@ -4,11 +4,19 @@ import ( "net/http" "net/http/httptest" + "github.com/google/uuid" middlewareapi "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/apis/middleware" . "github.com/onsi/ginkgo" . "github.com/onsi/gomega" ) +const ( + testRequestHeader = "X-Request-Id" + testRequestID = "11111111-2222-4333-8444-555555555555" + // mockRand io.Reader below counts bytes from 0-255 in order + testRandomUUID = "00010203-0405-4607-8809-0a0b0c0d0e0f" +) + var _ = Describe("Scope Suite", func() { Context("NewScope", func() { var request, nextRequest *http.Request @@ -24,10 +32,11 @@ var _ = Describe("Scope Suite", func() { Context("ReverseProxy is false", func() { BeforeEach(func() { - handler := NewScope(false)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - nextRequest = r - w.WriteHeader(200) - })) + handler := NewScope(false, testRequestHeader)( + http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + nextRequest = r + w.WriteHeader(200) + })) handler.ServeHTTP(rw, request) }) @@ -52,10 +61,11 @@ var _ = Describe("Scope Suite", func() { Context("ReverseProxy is true", func() { BeforeEach(func() { - handler := NewScope(true)(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { - nextRequest = r - w.WriteHeader(200) - })) + handler := NewScope(true, testRequestHeader)( + http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + nextRequest = r + w.WriteHeader(200) + })) handler.ServeHTTP(rw, request) }) @@ -65,5 +75,53 @@ var _ = Describe("Scope Suite", func() { Expect(scope.ReverseProxy).To(BeTrue()) }) }) + + Context("Request ID header is present", func() { + BeforeEach(func() { + request.Header.Add(testRequestHeader, testRequestID) + handler := NewScope(false, testRequestHeader)( + http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + nextRequest = r + w.WriteHeader(200) + })) + handler.ServeHTTP(rw, request) + }) + + It("sets the RequestID using the request", func() { + scope := middlewareapi.GetRequestScope(nextRequest) + Expect(scope.RequestID).To(Equal(testRequestID)) + }) + }) + + Context("Request ID header is missing", func() { + BeforeEach(func() { + uuid.SetRand(mockRand{}) + + handler := NewScope(true, testRequestHeader)( + http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + nextRequest = r + w.WriteHeader(200) + })) + handler.ServeHTTP(rw, request) + }) + + AfterEach(func() { + uuid.SetRand(nil) + }) + + It("sets the RequestID using a random UUID", func() { + scope := middlewareapi.GetRequestScope(nextRequest) + Expect(scope.RequestID).To(Equal(testRandomUUID)) + }) + }) }) }) + +type mockRand struct{} + +func (mockRand) Read(p []byte) (int, error) { + for i := range p { + p[i] = byte(i % 256) + } + return len(p), nil +} diff --git a/pkg/middleware/stored_session_test.go b/pkg/middleware/stored_session_test.go index 4a8fd9da..0ab6c994 100644 --- a/pkg/middleware/stored_session_test.go +++ b/pkg/middleware/stored_session_test.go @@ -401,6 +401,7 @@ var _ = Describe("Stored Session Suite", func() { } req := httptest.NewRequest("", "/", nil) + req = middlewareapi.AddRequestScope(req, &middlewareapi.RequestScope{}) refreshed, err := s.refreshSessionWithProvider(nil, req, in.session) if in.expectedErr != nil { Expect(err).To(MatchError(in.expectedErr)) diff --git a/pkg/requests/util/util.go b/pkg/requests/util/util.go index 08c9c2c1..9805db61 100644 --- a/pkg/requests/util/util.go +++ b/pkg/requests/util/util.go @@ -6,10 +6,16 @@ import ( middlewareapi "github.com/oauth2-proxy/oauth2-proxy/v7/pkg/apis/middleware" ) +const ( + XForwardedProto = "X-Forwarded-Proto" + XForwardedHost = "X-Forwarded-Host" + XForwardedURI = "X-Forwarded-Uri" +) + // GetRequestProto returns the request scheme or X-Forwarded-Proto if present // and the request is proxied. func GetRequestProto(req *http.Request) string { - proto := req.Header.Get("X-Forwarded-Proto") + proto := req.Header.Get(XForwardedProto) if !IsProxied(req) || proto == "" { proto = req.URL.Scheme } @@ -19,7 +25,7 @@ func GetRequestProto(req *http.Request) string { // GetRequestHost returns the request host header or X-Forwarded-Host if // present and the request is proxied. func GetRequestHost(req *http.Request) string { - host := req.Header.Get("X-Forwarded-Host") + host := req.Header.Get(XForwardedHost) if !IsProxied(req) || host == "" { host = req.Host } @@ -29,7 +35,7 @@ func GetRequestHost(req *http.Request) string { // GetRequestURI return the request URI or X-Forwarded-Uri if present and the // request is proxied. func GetRequestURI(req *http.Request) string { - uri := req.Header.Get("X-Forwarded-Uri") + uri := req.Header.Get(XForwardedURI) if !IsProxied(req) || uri == "" { // Use RequestURI to preserve ?query uri = req.URL.RequestURI() diff --git a/pkg/upstream/http_test.go b/pkg/upstream/http_test.go index c406e1c7..aecee5c7 100644 --- a/pkg/upstream/http_test.go +++ b/pkg/upstream/http_test.go @@ -390,7 +390,7 @@ var _ = Describe("HTTP Upstream Suite", func() { handler := newHTTPUpstreamProxy(upstream, u, nil, nil) - proxyServer = httptest.NewServer(middleware.NewScope(false)(handler)) + proxyServer = httptest.NewServer(middleware.NewScope(false, "X-Request-Id")(handler)) }) AfterEach(func() {