search

ory / kratos

The most scalable and customizable identity server on the market. Replace your Homegrown, Auth0, Okta, Firebase with better UX and DX. Has all the tablestakes: Passkeys, Social Sign In, Multi-Factor Auth, SMS, SAML, TOTP, and more. Written in Go, cloud native, headless, API-first. Available as a service on Ory Network and for self-hosters.
https://www.ory.sh/?utm_source=github&utm_medium=banner&utm_campaign=kratos
Apache License 2.0
11.3k stars 964 forks source link

Investigate MySQL empty timestamp issue on session #244

Closed aeneasr closed 4 years ago

aeneasr commented 4 years ago

Describe the bug

https://community.ory.sh/t/kratos-using-mysql-fails-to-create-a-session-when-sigining-in/1508/2

philipjkim commented 4 years ago

I'm trying to run kratos on localhost, using remote MySQL rather than SQLite.

What I've done are:

I used latest tag of oryd/kratos docker image instead of latest-sqlite since I'm not using SQLite. Here are my quickstart.yml:

version: "3.7"

services:
  kratos-selfservice-ui-node:
    image: oryd/kratos-selfservice-ui-node:latest
    ports:
      - "4435:4435"
    environment:
      - PORT=4435
      - KRATOS_PUBLIC_URL=http://kratos:4433/
      - KRATOS_ADMIN_URL=http://kratos:4434/
      - KRATOS_BROWSER_URL=http://127.0.0.1:4455/.ory/kratos/public
      - JWKS_URL=http://oathkeeper:4456/.well-known/jwks.json
    networks:
      - intranet
    restart: on-failure

  oathkeeper:
    image: oryd/oathkeeper:v0.35.5-beta.1
    depends_on:
      - kratos
    ports:
      - "4455:4455"
      - "4456:4456"
    command: serve proxy -c "/etc/config/oathkeeper/.oathkeeper.yml"
    environment:
      - LOG_LEVEL=debug
    restart: on-failure
    networks:
      - intranet
    volumes:
      - type: bind
        source: ./contrib/quickstart/oathkeeper
        target: /etc/config/oathkeeper

  kratos:
    image: oryd/kratos:latest
    ports:
      - "4433:4433" # public
      - "4434:4434" # admin
    restart: unless-stopped
    environment:
      - DSN=mysql://$MYSQL_USERNAME:$MYSQL_PASSWORD@tcp($MYSQL_ADDRESS)/$MYSQL_DATABASE?parseTime=true&multiStatements=true
    command: serve -c /etc/config/kratos/.kratos.yml --dev
    volumes:
      - type: bind
        source: ./contrib/quickstart/kratos/email-password
        target: /etc/config/kratos
    networks:
      - intranet

  mailhog:
    image: mailhog/mailhog:v1.0.0
    ports:
      - "8025:4436"
    networks:
      - intranet

networks:
  intranet:

The server starts without an error, so I reached to http://localhost:4455/dashboard and registered with email and password. Then I saw an error on the browser:

{
  "error": {
    "code": 500,
    "message": "Error 1292: Incorrect datetime value: '0000-00-00' for column 'seen_at' at row 1"
  }
}

I checked other tables if data were inserted, then I found those table have data:

Errors seen on sysout for docker processes are (prettified stactraces):

mysql create: Error 1292: Incorrect datetime value: '0000-00-00' for column 'authenticated_at' at row 1

Stack trace:
github.com/gobuffalo/pop/v5.(*mysql).Create
    /go/pkg/mod/github.com/gobuffalo/pop/v5@v5.0.7/dialect_mysql.go:83
github.com/gobuffalo/pop/v5.(*Connection).Create.func1.1
    /go/pkg/mod/github.com/gobuffalo/pop/v5@v5.0.7/executors.go:240
github.com/gobuffalo/pop/v5.(*Connection).timeFunc
    /go/pkg/mod/github.com/gobuffalo/pop/v5@v5.0.7/connection.go:228
github.com/gobuffalo/pop/v5.(*Connection).Create.func1
    /go/pkg/mod/github.com/gobuffalo/pop/v5@v5.0.7/executors.go:175
github.com/gobuffalo/pop/v5.(*Model).iterate
    /go/pkg/mod/github.com/gobuffalo/pop/v5@v5.0.7/model.go:222
github.com/gobuffalo/pop/v5.(*Connection).Create
    /go/pkg/mod/github.com/gobuffalo/pop/v5@v5.0.7/executors.go:174
github.com/ory/kratos/persistence/sql.(*Persister).CreateSession
    /home/ory/persistence/sql/persister_session.go:27
github.com/ory/kratos/selfservice/hook.(*SessionIssuer).ExecuteLoginPostHook
    /home/ory/selfservice/hook/session_issuer.go:35
github.com/ory/kratos/selfservice/flow/login.(*HookExecutor).PostLoginHook
    /home/ory/selfservice/flow/login/hook.go:46
github.com/ory/kratos/selfservice/strategy/password.(*Strategy).handleLogin
    /home/ory/selfservice/strategy/password/login.go:125
github.com/ory/kratos/session.(*Handler).IsNotAuthenticated.func1
    /home/ory/session/handler.go:108
github.com/julienschmidt/httprouter.(*Router).ServeHTTP
    /go/pkg/mod/github.com/julienschmidt/httprouter@v1.2.0/router.go:334
github.com/justinas/nosurf.(*CSRFHandler).handleSuccess
    /go/pkg/mod/github.com/justinas/nosurf@v0.0.0-20190118163749-6453469bdcc9/handler.go:187
github.com/justinas/nosurf.(*CSRFHandler).ServeHTTP
    /go/pkg/mod/github.com/justinas/nosurf@v0.0.0-20190118163749-6453469bdcc9/handler.go:180
github.com/urfave/negroni.Wrap.func1
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:46
github.com/urfave/negroni.HandlerFunc.ServeHTTP
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:29
github.com/urfave/negroni.middleware.ServeHTTP
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38
github.com/ory/x/metricsx.(*Service).ServeHTTP
    /go/pkg/mod/github.com/ory/x@v0.0.93/metricsx/middleware.go:261
github.com/urfave/negroni.middleware.ServeHTTP
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38
github.com/ory/x/reqlog.(*Middleware).ServeHTTP
    /go/pkg/mod/github.com/ory/x@v0.0.93/reqlog/middleware.go:140
github.com/urfave/negroni.middleware.ServeHTTP
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38
github.com/urfave/negroni.(*Negroni).ServeHTTP
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:96
github.com/gorilla/context.ClearHandler.func1
    /go/pkg/mod/github.com/gorilla/context@v1.1.1/context.go:141
net/http.HandlerFunc.ServeHTTP
    /usr/local/go/src/net/http/server.go:2007
net/http.serverHandler.ServeHTTP
    /usr/local/go/src/net/http/server.go:2802
net/http.(*conn).serve
    /usr/local/go/src/net/http/server.go:1890
runtime.goexit
    /usr/local/go/src/runtime/asm_amd64.s:1357

and

Error 1292: Incorrect datetime value: '0000-00-00' for column 'seen_at' at row 1

Stack trace:
github.com/ory/x/sqlcon.HandleError
    /go/pkg/mod/github.com/ory/x@v0.0.93/sqlcon/error.go:55
github.com/ory/kratos/persistence/sql.(*Persister).Add
    /home/ory/persistence/sql/persister_errorx.go:36
github.com/ory/kratos/selfservice/errorx.(*Manager).Create
    /home/ory/selfservice/errorx/manager.go:54
github.com/ory/kratos/selfservice/errorx.(*Manager).Forward
    /home/ory/selfservice/errorx/manager.go:67
github.com/ory/kratos/selfservice/flow/registration.(*ErrorHandler).HandleRegistrationError
    /home/ory/selfservice/flow/registration/error.go:79
github.com/ory/kratos/selfservice/strategy/password.(*Strategy).handleRegistrationError
    /home/ory/selfservice/strategy/password/registration.go:81
github.com/ory/kratos/selfservice/strategy/password.(*Strategy).handleRegistration
    /home/ory/selfservice/strategy/password/registration.go:198
github.com/ory/kratos/session.(*Handler).IsNotAuthenticated.func1
    /home/ory/session/handler.go:108
github.com/julienschmidt/httprouter.(*Router).ServeHTTP
    /go/pkg/mod/github.com/julienschmidt/httprouter@v1.2.0/router.go:334
github.com/justinas/nosurf.(*CSRFHandler).handleSuccess
    /go/pkg/mod/github.com/justinas/nosurf@v0.0.0-20190118163749-6453469bdcc9/handler.go:187
github.com/justinas/nosurf.(*CSRFHandler).ServeHTTP
    /go/pkg/mod/github.com/justinas/nosurf@v0.0.0-20190118163749-6453469bdcc9/handler.go:180
github.com/urfave/negroni.Wrap.func1
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:46
github.com/urfave/negroni.HandlerFunc.ServeHTTP
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:29
github.com/urfave/negroni.middleware.ServeHTTP
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38
github.com/ory/x/metricsx.(*Service).ServeHTTP
    /go/pkg/mod/github.com/ory/x@v0.0.93/metricsx/middleware.go:261
github.com/urfave/negroni.middleware.ServeHTTP
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38
github.com/ory/x/reqlog.(*Middleware).ServeHTTP
    /go/pkg/mod/github.com/ory/x@v0.0.93/reqlog/middleware.go:140
github.com/urfave/negroni.middleware.ServeHTTP
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:38
github.com/urfave/negroni.(*Negroni).ServeHTTP
    /go/pkg/mod/github.com/urfave/negroni@v1.0.0/negroni.go:96
github.com/gorilla/context.ClearHandler.func1
    /go/pkg/mod/github.com/gorilla/context@v1.1.1/context.go:141
net/http.HandlerFunc.ServeHTTP
    /usr/local/go/src/net/http/server.go:2007
net/http.serverHandler.ServeHTTP
    /usr/local/go/src/net/http/server.go:2802
net/http.(*conn).serve
    /usr/local/go/src/net/http/server.go:1890
runtime.goexit
    /usr/local/go/src/runtime/asm_amd64.s:1357

And MySQL version is 5.7.29. With SQLite I had no problem signing in. Please give some help to solve the problem.

philipjkim commented 4 years ago

FYI, I had a test with Postgres; it works well without datetime column error.

aeneasr commented 4 years ago

Thank you for investigating! I've triaged this issue for 0.1.1 so we'll hopefully have a fix for that version then.

aeneasr commented 4 years ago

Closed via #246

philipjkim commented 4 years ago

@aeneasr I think a similar problem occurs when creating an ErrorContainer because of its SeenAt field's not initialized. It's the second error/trace in https://github.com/ory/kratos/issues/244#issuecomment-584936460 .

aeneasr commented 4 years ago

Yup! :) Thanks :)