Skip to content

504 Timeout when refreshing token #1295

Closed
@paulrostorp

Description

I am calling my refresh token function in the background (from inside cluster) and getting gateway timeout error. This function works and successfully refreshes the token when running outside my cluster. Note that I am terminating TLS at the edge and have configured hydra properly I believe (using HTTPS_ALLOW_TERMINATION_FROM environment variable).
Anyways I get the following error:

{ HTTPError: Response code 504 (Gateway Timeout)
    at stream.catch.then.data (/usr/src/app/node_modules/got/index.js:386:13)
    at process._tickCallback (internal/process/next_tick.js:68:7)
  name: 'HTTPError',
  host: 'oauth2.polluxis.me',
  hostname: 'oauth2.polluxis.me',
  method: 'POST',
  path: '/oauth2/token',
  protocol: 'https:',
  url: 'https://oauth2.polluxis.me/oauth2/token',
  statusCode: 504,
  statusMessage: 'Gateway Timeout',
  headers:
   { 'content-length': '24',
     'content-type': 'text/plain',
     date: 'Thu, 28 Feb 2019 17:17:22 GMT',
     server: 'envoy',
     connection: 'close' } }

Meanwhile the hydra pod logs

time="2019-03-01T09:25:51Z" level=debug msg="Stack trace: \ngithub.com/ory/fosite/handler/oauth2.(*RefreshTokenGrantHandler).PopulateTokenEndpointResponse\n\t/go/pkg/mod/github.com/ory/fosite@v0.28.0/handler/oauth2/flow_refresh.go:129\ngithub.com/ory/fosite.(*Fosite).NewAccessResponse\n\t/go/pkg/mod/github.com/ory/fosite@v0.28.0/access_response_writer.go:36\ngithub.com/ory/hydra/oauth2.(*Handler).TokenHandler\n\t/go/src/github.com/ory/hydra/oauth2/handler.go:572\ngithub.com/ory/hydra/oauth2.(*Handler).TokenHandler-fm\n\t/go/src/github.com/ory/hydra/oauth2/handler.go:172\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:1964\ngithub.com/rs/cors.(*Cors).Handler.func1\n\t/go/pkg/mod/github.com/rs/cors@v1.6.0/cors.go:207\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:1964\ngithub.com/julienschmidt/httprouter.(*Router).Handler.func1\n\t/go/pkg/mod/github.com/julienschmidt/httprouter@v0.0.0-20180715161854-348b672cd90d/params_go17.go:26\ngithub.com/julienschmidt/httprouter.(*Router).ServeHTTP\n\t/go/pkg/mod/github.com/julienschmidt/httprouter@v0.0.0-20180715161854-348b672cd90d/router.go:334\ngithub.com/urfave/negroni.Wrap.func1\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:46\ngithub.com/urfave/negroni.HandlerFunc.ServeHTTP\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:29\ngithub.com/urfave/negroni.middleware.ServeHTTP\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38\ngithub.com/urfave/negroni.middleware.ServeHTTP-fm\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:1964\ngithub.com/ory/hydra/cmd/server.(*Handler).RejectInsecureRequests\n\t/go/src/github.com/ory/hydra/cmd/server/handler.go:297\ngithub.com/ory/hydra/cmd/server.(*Handler).RejectInsecureRequests-fm\n\t/go/src/github.com/ory/hydra/cmd/server/handler.go:62\ngithub.com/urfave/negroni.HandlerFunc.ServeHTTP\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:29\ngithub.com/urfave/negroni.middleware.ServeHTTP\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38\ngithub.com/urfave/negroni.middleware.ServeHTTP-fm\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38\ngithub.com/ory/hydra/metrics/prometheus.(*MetricsManager).ServeHTTP\n\t/go/src/github.com/ory/hydra/metrics/prometheus/middleware.go:26\ngithub.com/urfave/negroni.middleware.ServeHTTP\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38\ngithub.com/urfave/negroni.middleware.ServeHTTP-fm\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38\ngithub.com/meatballhat/negroni-logrus.(*Middleware).ServeHTTP\n\t/go/pkg/mod/github.com/meatballhat/negroni-logrus@v0.0.0-20170801195057-31067281800f/middleware.go:136\ngithub.com/urfave/negroni.middleware.ServeHTTP\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38\ngithub.com/urfave/negroni.(*Negroni).ServeHTTP\n\t/go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:96\ngithub.com/gorilla/context.ClearHandler.func1\n\t/go/pkg/mod/github.com/gorilla/context@v1.1.1/context.go:141\nnet/http.HandlerFunc.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:1964\nnet/http.serverHandler.ServeHTTP\n\t/usr/local/go/src/net/http/server.go:2741\nnet/http.(*conn).serve\n\t/usr/local/go/src/net/http/server.go:1847\nruntime.goexit\n\t/usr/local/go/src/runtime/asm_amd64.s:1333"
time="2019-03-01T09:25:51Z" level=info msg="completed handling request" measure#https://oauth2.polluxis.me/.latency=3192799314 method=POST remote="10.244.92.0:43498" request=/oauth2/token request_id=a46b771e-2c47-42b4-9a38-b7acc4c33709 status=500 text_status="Internal Server Error" took=3.192799314s
time="2019-02-28T17:17:24Z" level=error msg="An error occurred" debug="context canceled" description="The authorization server encountered an unexpected condition that prevented it from fulfilling the request" error=server_error

What does the "context cancelled" mean ? How should I go about debugging this ?

Kubernetes: v1.12.2
Hydra: oryd/hydra:v1.0.0-rc.6_oryOS.10
DB: Postgres

Environment variables:
- name: LOG_LEVEL
value: "debug"
- name: OAUTH2_SHARE_ERROR_DEBUG
value: "true"
- name: ACCESS_TOKEN_LIFESPAN
value: 2m
- name: CORS_ENABLED
value: "true"
- name: CORS_ALLOWED_ORIGINS
value: ""
- name: CORS_ALLOWED_HEADERS
value: "Origin,X-Requested-With,Content-Type,Accept,authorization"
- name: HTTPS_ALLOW_TERMINATION_FROM
value: 10.244.0.0/16
- name: OAUTH2_ISSUER_URL
value: https://oauth2.polluxis.me/
- name: OAUTH2_CONSENT_URL
value: https://auth.polluxis.me/consent
- name: OAUTH2_LOGIN_URL
value: https://auth.polluxis.me/login
- name: DATABASE_URL
value: postgres://
**?sslmode=disable
- name: SYSTEM_SECRET
value: **

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions