Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Investigate MySQL empty timestamp issue on session #244

Closed
aeneasr opened this issue Feb 11, 2020 · 6 comments
Closed

Investigate MySQL empty timestamp issue on session #244

aeneasr opened this issue Feb 11, 2020 · 6 comments
Labels
bug Something is not working.
Milestone
v0.2.0-alpha.1

Comments

@aeneasr
Copy link
Member

aeneasr commented Feb 11, 2020

Describe the bug

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

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

What I've done are:

  • Schema migration on the remote MySQL DB
  • Run kratos using docker-compose with customized quickstart.yml

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:

  • identities
  • identity_credential_identifiers
  • identity_credential_types
  • identity_credentials
  • selfservice_login_request_methods
  • selfservice_login_requests
  • selfservice_registration_request_methods
  • selfservice_registration_requests

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
Copy link

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

@aeneasr aeneasr added the bug Something is not working. label Feb 12, 2020
@aeneasr aeneasr added this to the v0.1.1-alpha.1 milestone Feb 12, 2020
@aeneasr
Copy link
Member Author

aeneasr commented Feb 12, 2020

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 aeneasr mentioned this issue Feb 13, 2020
Merged
@aeneasr
Copy link
Member Author

aeneasr commented Feb 13, 2020

Closed via #246

@aeneasr aeneasr closed this as completed Feb 13, 2020
@philipjkim
Copy link

@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 #244 (comment) .

@aeneasr aeneasr reopened this Feb 14, 2020
@aeneasr
Copy link
Member Author

aeneasr commented Feb 14, 2020

Yup! :) Thanks :)

@philipjkim philipjkim mentioned this issue Feb 18, 2020
Closed
6 tasks
aeneasr added a commit that referenced this issue Feb 19, 2020
@aeneasr
fix: Resolve NULL value for seen_at
462c7c6 
Closes #244
@aeneasr aeneasr closed this as completed in a7d1e86 Mar 5, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something is not working.
Projects
None yet
Milestone
v0.2.0-alpha.1
Development

No branches or pull requests
2 participants
@philipjkim @aeneasr