Auth/Token naming mismatch

[Reeywhaar]

Noticed, that although readme tells to use {website}/auth/{prov}/callback, the code uses {website}/token/{prov}/callback judging by https://github.com/go-pkgz/auth/blob/master/provider/providers.go and logs.

[umputun]

yeah, probably bad side effect of refactoring I did. It used to be auth.Blah but to avoid conflicts renamed "auth" package to "token". I think IDEA tried to be "too helpful" and also renamed part of strings.

[umputun]

should be addressed by 1efb960

[Reeywhaar]

So, right now with github callback mismatch error message is gone, but now there is internal server error. After I authorize test app, I get redirected to http://127.0.0.1:8080/auth/github/callback?code={code}&state={state} which shows said error, and in logs there is:

auth-example    | 2018/12/29 18:12:30 [DEBUG] login with github
auth-example    | 2018/12/29 18:12:30 [DEBUG] login url https://github.com/login/oauth/authorize?{hidden}, claims={StandardClaims:{Audience: ExpiresAt:1546130550 Id:4ad16491c3c95d04250c6406efabf1e45b28004f IssuedAt:0 Issuer: NotBefore:1546128690 Subject:} User:<nil> SessionOnly:false Handshake:0xc000187e30}
auth-example    | 2018/12/29 18:12:30 [REST] GET - /auth/github/login?id=auth-example&from=http://localhost:8080/web/?close=true - 192.168.48.1 - 302 (242) - 1.3807ms
auth-example    | 2018/12/29 18:12:31 [REST] GET - /auth/github/callback?code={hidden code}&state={hidden state} - 192.168.48.1 - 200 (0) - 299.7µs
auth-example    | 2018/12/29 18:12:31 [WARN] request panic, runtime error: invalid memory address or nil pointer dereference
auth-example    | 2018/12/29 18:12:31 goroutine 38 [running]:
auth-example    | runtime/debug.Stack(0x8b07be, 0x18, 0xc0001c0848)
auth-example    |       /usr/local/go/src/runtime/debug/stack.go:24 +0xa7
auth-example    | github.com/go-pkgz/rest.Recoverer.func1.1(0x923c80, 0xc000140c40)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/middleware.go:51 +0x94
auth-example    | panic(0x82f9e0, 0xbf8f90)
auth-example    |       /usr/local/go/src/runtime/panic.go:513 +0x1b9
auth-example    | github.com/go-pkgz/auth/provider.Service.authHandler(0x8af01d, 0x15, 0xc000132000, 0xc0000b0880, 0xc000024012, 0x14, 0xc000026013, 0x28, 0x0, 0x0, ...)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/auth@v0.0.0-20181229195356-6fd1430b0893/provider/service.go:147 +0x126
auth-example    | github.com/go-pkgz/auth/provider.Service.Handler(0x8af01d, 0x15, 0xc000132000, 0xc0000b0880, 0xc000024012, 0x14, 0xc000026013, 0x28, 0x0, 0x0, ...)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/auth@v0.0.0-20181229195356-6fd1430b0893/provider/service.go:85 +0x26e
auth-example    | github.com/go-pkgz/auth.(*Service).Handlers.func1(0x9236c0, 0xc000250880, 0xc00020e700)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/auth@v0.0.0-20181229195356-6fd1430b0893/auth.go:154 +0x6c4
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc00006b470, 0x9236c0, 0xc000250880, 0xc00020e700)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-chi/chi.(*Mux).Mount.func1(0x9236c0, 0xc000250880, 0xc00020e700)
auth-example    |       /go/pkg/mod/github.com/go-chi/chi@v3.3.3+incompatible/mux.go:291 +0xf5
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc000076ba0, 0x9236c0, 0xc000250880, 0xc00020e700)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-chi/chi.(*Mux).routeHTTP(0xc0000846c0, 0x9236c0, 0xc000250880, 0xc00020e700)
auth-example    |       /go/pkg/mod/github.com/go-chi/chi@v3.3.3+incompatible/mux.go:424 +0x239
auth-example    | github.com/go-chi/chi.(*Mux).routeHTTP-fm(0x9236c0, 0xc000250880, 0xc00020e700)
auth-example    |       /go/pkg/mod/github.com/go-chi/chi@v3.3.3+incompatible/mux.go:368 +0x48
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc00006b3f0, 0x9236c0, 0xc000250880, 0xc00020e700)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-pkgz/rest/logger.(*Middleware).Handler.func1(0x923c80, 0xc000140c40, 0xc00020e700)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/logger/logger.go:93 +0x1cc
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc0000769a0, 0x923c80, 0xc000140c40, 0xc00020e700)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-pkgz/rest.Recoverer.func1(0x923c80, 0xc000140c40, 0xc00020e700)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/middleware.go:55 +0x95
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc0000769c0, 0x923c80, 0xc000140c40, 0xc00020e700)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-pkgz/rest.Ping.func1(0x923c80, 0xc000140c40, 0xc00020e700)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/middleware.go:40 +0x68
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc0000769e0, 0x923c80, 0xc000140c40, 0xc00020e700)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-pkgz/rest.AppInfo.func1.1(0x923c80, 0xc000140c40, 0xc00020e700)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/middleware.go:21 +0x1c3
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc000094410, 0x923c80, 0xc000140c40, 0xc00020e700)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-chi/chi.(*Mux).ServeHTTP(0xc0000846c0, 0x923c80, 0xc000140c40, 0xc00020e600)
auth-example    |       /go/pkg/mod/github.com/go-chi/chi@v3.3.3+incompatible/mux.go:81 +0x293
auth-example    | net/http.serverHandler.ServeHTTP(0xc0000736c0, 0x923c80, 0xc000140c40, 0xc00020e600)
auth-example    |       /usr/local/go/src/net/http/server.go:2741 +0xab
auth-example    | net/http.(*conn).serve(0xc00018e780, 0x924140, 0xc0001b26c0)
auth-example    |       /usr/local/go/src/net/http/server.go:1847 +0x646
auth-example    | created by net/http.(*Server).Serve
auth-example    |       /usr/local/go/src/net/http/server.go:2851 +0x2f5

[umputun]

looks like somehow instead of handshake token it got the final JWT. I have not tested it yet with the real provider, planning to do it later on today.

[Reeywhaar]

Same Internal Server Error with dev oauth, bad IDEA :-)

Log

auth-example    | 2018/12/29 19:00:35 [DEBUG] login with dev
auth-example    | 2018/12/29 19:00:35 [DEBUG] login url http://127.0.0.1:8084/login/oauth/authorize?client_id=&redirect_uri=http%3A%2F%2F127.0.0.1%3A8080%2Fauth%2Fdev%2Fcallback&response_type=code&scope=user%3Aemail&state=13ba02f6debcea8790323ca55eafd447dfa751f9, claims={StandardClaims:{Audience: ExpiresAt:1546133435 Id:982cc07a8ef8867f037ae7b1be918c7fad41a0a0 IssuedAt:0 Issuer: NotBefore:1546131575 Subject:} User: SessionOnly:false Handshake:0xc00026c3c0}
auth-example    | 2018/12/29 19:00:35 [REST] GET - /auth/dev/login?id=auth-example&from=http://localhost:8080/web/?close=true - 192.168.48.1 - 302 (245) - 276.5µs
auth-example    | 2018/12/29 19:00:35 [DEBUG] dev oauth request GET /login/oauth/authorize?client_id=&redirect_uri=http%3A%2F%2F127.0.0.1%3A8080%2Fauth%2Fdev%2Fcallback&response_type=code&scope=user%3Aemail&state=13ba02f6debcea8790323ca55eafd447dfa751f9 map[Accept:[text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8] Accept-Language:[en-US,en;q=0.5] Accept-Encoding:[gzip, deflate] Referer:[http://127.0.0.1:8084/login/oauth/authorize?client_id=&redirect_uri=http%3A%2F%2F127.0.0.1%3A8080%2Fauth%2Fdev%2Fcallback&response_type=code&scope=user%3Aemail&state=13ba02f6debcea8790323ca55eafd447dfa751f9] Dnt:[1] Connection:[keep-alive] Cookie:[JWT=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJleHAiOjE1NDYwOTI5MTksImp0aSI6ImVjMTI4NWZkMzc5Y2U0YjhiMjYwZDY3MDFkYTNjODI3NmIwYTE2M2YiLCJpc3MiOiJteS1kZW1vLXNlcnZpY2UiLCJ1c2VyIjp7Im5hbWUiOiJkZXZfdXNlciIsImlkIjoiZGV2X3VzZXIiLCJwaWN0dXJlIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL2F2YXRhci9jY2ZhMmFiZDAxNjY3NjA1YjRlMWZjNGZjYjkxYjFlMWFmMzIzMjQwLmltYWdlIn19.hhHp-5baA2Ly78hajyW6xAf4-PVXRkdJFmuMxqO4ZpA; XSRF-TOKEN=ec1285fd379ce4b8b260d6701da3c8276b0a163f] Upgrade-Insecure-Requests:[1] User-Agent:[Mozilla/5.0 (Macintosh; Intel Mac OS X 10.13; rv:65.0) Gecko/20100101 Firefox/65.0]]
auth-example    | 2018/12/29 19:00:36 [DEBUG] dev oauth request GET /favicon.ico map[User-Agent:[Mozilla/5.0 (Macintosh; Intel Mac OS X 10.13; rv:65.0) Gecko/20100101 Firefox/65.0] Accept:[text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8] Accept-Language:[en-US,en;q=0.5] Accept-Encoding:[gzip, deflate] Dnt:[1] Connection:[keep-alive] Cookie:[JWT=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJleHAiOjE1NDYwOTI5MTksImp0aSI6ImVjMTI4NWZkMzc5Y2U0YjhiMjYwZDY3MDFkYTNjODI3NmIwYTE2M2YiLCJpc3MiOiJteS1kZW1vLXNlcnZpY2UiLCJ1c2VyIjp7Im5hbWUiOiJkZXZfdXNlciIsImlkIjoiZGV2X3VzZXIiLCJwaWN0dXJlIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL2F2YXRhci9jY2ZhMmFiZDAxNjY3NjA1YjRlMWZjNGZjYjkxYjFlMWFmMzIzMjQwLmltYWdlIn19.hhHp-5baA2Ly78hajyW6xAf4-PVXRkdJFmuMxqO4ZpA; XSRF-TOKEN=ec1285fd379ce4b8b260d6701da3c8276b0a163f]]
auth-example    | 2018/12/29 19:00:36 [DEBUG] dev oauth request POST /login/oauth/authorize?client_id=&redirect_uri=http%3A%2F%2F127.0.0.1%3A8080%2Fauth%2Fdev%2Fcallback&response_type=code&scope=user%3Aemail&state=13ba02f6debcea8790323ca55eafd447dfa751f9 map[Cookie:[JWT=eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJleHAiOjE1NDYwOTI5MTksImp0aSI6ImVjMTI4NWZkMzc5Y2U0YjhiMjYwZDY3MDFkYTNjODI3NmIwYTE2M2YiLCJpc3MiOiJteS1kZW1vLXNlcnZpY2UiLCJ1c2VyIjp7Im5hbWUiOiJkZXZfdXNlciIsImlkIjoiZGV2X3VzZXIiLCJwaWN0dXJlIjoiaHR0cDovLzEyNy4wLjAuMTo4MDgwL2F2YXRhci9jY2ZhMmFiZDAxNjY3NjA1YjRlMWZjNGZjYjkxYjFlMWFmMzIzMjQwLmltYWdlIn19.hhHp-5baA2Ly78hajyW6xAf4-PVXRkdJFmuMxqO4ZpA; XSRF-TOKEN=ec1285fd379ce4b8b260d6701da3c8276b0a163f] Upgrade-Insecure-Requests:[1] Content-Type:[application/x-www-form-urlencoded] Dnt:[1] Accept-Encoding:[gzip, deflate] Referer:[http://127.0.0.1:8084/login/oauth/authorize?client_id=&redirect_uri=http%3A%2F%2F127.0.0.1%3A8080%2Fauth%2Fdev%2Fcallback&response_type=code&scope=user%3Aemail&state=13ba02f6debcea8790323ca55eafd447dfa751f9] Content-Length:[17] Connection:[keep-alive] User-Agent:[Mozilla/5.0 (Macintosh; Intel Mac OS X 10.13; rv:65.0) Gecko/20100101 Firefox/65.0] Accept:[text/html,application/xhtml+xml,application/xml;q=0.9,image/webp,*/*;q=0.8] Accept-Language:[en-US,en;q=0.5]]
auth-example    | 2018/12/29 19:00:36 [DEBUG] callback url=http://127.0.0.1:8080/auth/dev/callback?code=g0ZGZmNjVmOWI&state=13ba02f6debcea8790323ca55eafd447dfa751f9
auth-example    | 2018/12/29 19:00:36 [DEBUG] invalid handshake token -  - 403 - 192.168.48.1 - /auth/dev/callback?code=g0ZGZmNjVmOWI&state=13ba02f6debcea8790323ca55eafd447dfa751f9 [caused by auth@v0.0.0-20181230004831-e5a9bfced877/provider/service.go:148 provider.Service.authHandler]
auth-example    | 2018/12/29 19:00:36 [REST] GET - /auth/dev/callback?code=g0ZGZmNjVmOWI&state=13ba02f6debcea8790323ca55eafd447dfa751f9 - 192.168.48.1 - 403(0) - 356.8µs
auth-example    | 2018/12/29 19:00:36 [WARN] request panic, runtime error: invalid memory address or nil pointer dereference
auth-example    | 2018/12/29 19:00:36 goroutine 63 [running]:
auth-example    | runtime/debug.Stack(0x8b0895, 0x18, 0xc0002847a0)
auth-example    |       /usr/local/go/src/runtime/debug/stack.go:24 +0xa7
auth-example    | github.com/go-pkgz/rest.Recoverer.func1.1(0x923e00, 0xc000173420)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/middleware.go:51 +0x94
auth-example    | panic(0x82fa00, 0xbf8f90)
auth-example    |       /usr/local/go/src/runtime/panic.go:513 +0x1b9
auth-example    | github.com/go-pkgz/rest.SendErrorJSON(0x923840, 0xc000269b80, 0xc000237000, 0x193, 0x0, 0x0, 0x8b0211, 0x17)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/httperrors.go:16 +0x13e
auth-example    | github.com/go-pkgz/auth/provider.Service.authHandler(0x8af0dd, 0x15, 0xc000132000, 0xc0000b0880, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/auth@v0.0.0-20181230004831-e5a9bfced877/provider/service.go:148 +0xf34
auth-example    | github.com/go-pkgz/auth/provider.Service.Handler(0x8af0dd, 0x15, 0xc000132000, 0xc0000b0880, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/auth@v0.0.0-20181230004831-e5a9bfced877/provider/service.go:85 +0x26e
auth-example    | github.com/go-pkgz/auth.(*Service).Handlers.func1(0x923840, 0xc000269b80, 0xc000237000)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/auth@v0.0.0-20181230004831-e5a9bfced877/auth.go:154 +0x6c4
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc00006b470, 0x923840, 0xc000269b80, 0xc000237000)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-chi/chi.(*Mux).Mount.func1(0x923840, 0xc000269b80, 0xc000237000)
auth-example    |       /go/pkg/mod/github.com/go-chi/chi@v3.3.3+incompatible/mux.go:291 +0xf5
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc000074bc0, 0x923840, 0xc000269b80, 0xc000237000)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-chi/chi.(*Mux).routeHTTP(0xc0000846c0, 0x923840, 0xc000269b80, 0xc000237000)
auth-example    |       /go/pkg/mod/github.com/go-chi/chi@v3.3.3+incompatible/mux.go:424 +0x239
auth-example    | github.com/go-chi/chi.(*Mux).routeHTTP-fm(0x923840, 0xc000269b80, 0xc000237000)
auth-example    |       /go/pkg/mod/github.com/go-chi/chi@v3.3.3+incompatible/mux.go:368 +0x48
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc00006b3f0, 0x923840, 0xc000269b80, 0xc000237000)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-pkgz/rest/logger.(*Middleware).Handler.func1(0x923e00, 0xc000173420, 0xc000237000)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/logger/logger.go:93 +0x1cc
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc0000749c0, 0x923e00, 0xc000173420, 0xc000237000)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-pkgz/rest.Recoverer.func1(0x923e00, 0xc000173420, 0xc000237000)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/middleware.go:55 +0x95
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc0000749e0, 0x923e00, 0xc000173420, 0xc000237000)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-pkgz/rest.Ping.func1(0x923e00, 0xc000173420, 0xc000237000)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/middleware.go:40 +0x68
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc000074a00, 0x923e00, 0xc000173420, 0xc000237000)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-pkgz/rest.AppInfo.func1.1(0x923e00, 0xc000173420, 0xc000237000)
auth-example    |       /go/pkg/mod/github.com/go-pkgz/rest@v1.1.2/middleware.go:21 +0x1c3
auth-example    | net/http.HandlerFunc.ServeHTTP(0xc000094410, 0x923e00, 0xc000173420, 0xc000237000)
auth-example    |       /usr/local/go/src/net/http/server.go:1964 +0x44
auth-example    | github.com/go-chi/chi.(*Mux).ServeHTTP(0xc0000846c0, 0x923e00, 0xc000173420, 0xc000236f00)
auth-example    |       /go/pkg/mod/github.com/go-chi/chi@v3.3.3+incompatible/mux.go:81 +0x293
auth-example    | net/http.serverHandler.ServeHTTP(0xc000077520, 0x923e00, 0xc000173420, 0xc000236f00)
auth-example    |       /usr/local/go/src/net/http/server.go:2741 +0xab
auth-example    | net/http.(*conn).serve(0xc00016ae60, 0x9242c0, 0xc00005adc0)
auth-example    |       /usr/local/go/src/net/http/server.go:1847 +0x646
auth-example    | created by net/http.(*Server).Serve
auth-example    |       /usr/local/go/src/net/http/server.go:2851 +0x2f5
auth-example    | 2018/12/29 19:00:36 http: multiple response.WriteHeader calls

[umputun]

tried to reproduce, but can't get any error. Both dev and github did the right thing. I have tried the current "/private", i.e. http://127.0.0.1:8080/auth/dev/login?from=/private and http://127.0.0.1:8080/auth/github/login?from=/private

Try to pool and rebuild container

[Reeywhaar]

Yes, I found that it works fine when login from http://127.0.0.1:8080/web/ but error when from http://localhost:8080/web/, dev issue.