User can register but can't login anymore once disconnected #408

Closed
opened 2018-12-04 15:29:19 +00:00 by gitlab-ghost-3733 · 8 comments

Hello,

I opened registrations on twinkaga.in today, with Pleroma updated to commit 88b05aea. Users can register and do everything on their account, but when disconnected, they can't relogin anymore. Here's the log of when they try to relogin.

Dec 04 16:12:23 blackmesa mix[6011]: 16:12:23.154 request_id=2lmijr49gvep0vnil80009ah [info] GET /nodeinfo/2.0.json
Dec 04 16:12:23 blackmesa mix[6011]: 16:12:23.156 request_id=2lmijr49gvep0vnil80009ah [info] Sent 200 in 1ms
Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.415 request_id=2lmijr8g9qbh2k3s040009b1 [info] POST /api/v1/apps
Dec 04 16:12:25 blackmesa mix[6011]: #Ecto.Changeset<
Dec 04 16:12:25 blackmesa mix[6011]:   action: nil,
Dec 04 16:12:25 blackmesa mix[6011]:   changes: %{
Dec 04 16:12:25 blackmesa mix[6011]:     client_id: "nt0Te5Cy6LJ_mnsKCx10jQO_BePdXLq3_ij6Ky6ipm0=",
Dec 04 16:12:25 blackmesa mix[6011]:     client_name: "PleromaFE_0.46968103918748183",
Dec 04 16:12:25 blackmesa mix[6011]:     client_secret: "[REDACTED]",
Dec 04 16:12:25 blackmesa mix[6011]:     redirect_uris: "https://twinkaga.in/oauth-callback",
Dec 04 16:12:25 blackmesa mix[6011]:     scopes: "read write follow"
Dec 04 16:12:25 blackmesa mix[6011]:   },
Dec 04 16:12:25 blackmesa mix[6011]:   errors: [],
Dec 04 16:12:25 blackmesa mix[6011]:   data: #Pleroma.Web.OAuth.App<>,
Dec 04 16:12:25 blackmesa mix[6011]:   valid?: true
Dec 04 16:12:25 blackmesa mix[6011]: >
Dec 04 16:12:25 blackmesa mix[6011]: {:ok,
Dec 04 16:12:25 blackmesa mix[6011]:  %Pleroma.Web.OAuth.App{
Dec 04 16:12:25 blackmesa mix[6011]:    __meta__: #Ecto.Schema.Metadata<:loaded, "apps">,
Dec 04 16:12:25 blackmesa mix[6011]:    client_id: "nt0Te5Cy6LJ_mnsKCx10jQO_BePdXLq3_ij6Ky6ipm0=",
Dec 04 16:12:25 blackmesa mix[6011]:    client_name: "PleromaFE_0.46968103918748183",
Dec 04 16:12:25 blackmesa mix[6011]:    client_secret: "[REDACTED]",
Dec 04 16:12:25 blackmesa mix[6011]:    id: 52,
Dec 04 16:12:25 blackmesa mix[6011]:    inserted_at: ~N[2018-12-04 15:12:25.417070],
Dec 04 16:12:25 blackmesa mix[6011]:    redirect_uris: "https://twinkaga.in/oauth-callback",
Dec 04 16:12:25 blackmesa mix[6011]:    scopes: "read write follow",
Dec 04 16:12:25 blackmesa mix[6011]:    updated_at: ~N[2018-12-04 15:12:25.417094],
Dec 04 16:12:25 blackmesa mix[6011]:    website: nil
Dec 04 16:12:25 blackmesa mix[6011]:  }}
Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.419 request_id=2lmijr8g9qbh2k3s040009b1 [info] Sent 200 in 3ms
Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.520 request_id=2lmijr8mhgb1tvqdmk0009bh [info] POST /oauth/token
Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.523 request_id=2lmijr8mhgb1tvqdmk0009bh [info] Sent 400 in 3ms
Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.661 request_id=2lmijr8uuuje25tek00009c1 [info] POST /api/account/verify_credentials.json
Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.661 request_id=2lmijr8uuuje25tek00009c1 [info] Sent 403 in 106µs
Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.663 request_id=2lmijr8v36g5d3f3dk0009ch [info] GET /api/statuses/friends_timeline.json
Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.663 request_id=2lmijr8v36g5d3f3dk0009ch [info] Sent 403 in 69µs

MastodonFE and PleromaFE have both this error.
I tried cleaning and recompiling deps, cleaning and recompiling Pleroma (mix clean, mix compile), I created uuid-ossp in Postgres (because when you make ecto.migrate, there was an error of insufficient privileges when creating the extension), but nothing really explains why it happens. It's the first time it's doing this error, I still can connect to my accounts.

Hello, I opened registrations on twinkaga.in today, with Pleroma updated to commit 88b05aea. Users can register and do everything on their account, but when disconnected, they can't relogin anymore. Here's the log of when they try to relogin. ``` Dec 04 16:12:23 blackmesa mix[6011]: 16:12:23.154 request_id=2lmijr49gvep0vnil80009ah [info] GET /nodeinfo/2.0.json Dec 04 16:12:23 blackmesa mix[6011]: 16:12:23.156 request_id=2lmijr49gvep0vnil80009ah [info] Sent 200 in 1ms Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.415 request_id=2lmijr8g9qbh2k3s040009b1 [info] POST /api/v1/apps Dec 04 16:12:25 blackmesa mix[6011]: #Ecto.Changeset< Dec 04 16:12:25 blackmesa mix[6011]: action: nil, Dec 04 16:12:25 blackmesa mix[6011]: changes: %{ Dec 04 16:12:25 blackmesa mix[6011]: client_id: "nt0Te5Cy6LJ_mnsKCx10jQO_BePdXLq3_ij6Ky6ipm0=", Dec 04 16:12:25 blackmesa mix[6011]: client_name: "PleromaFE_0.46968103918748183", Dec 04 16:12:25 blackmesa mix[6011]: client_secret: "[REDACTED]", Dec 04 16:12:25 blackmesa mix[6011]: redirect_uris: "https://twinkaga.in/oauth-callback", Dec 04 16:12:25 blackmesa mix[6011]: scopes: "read write follow" Dec 04 16:12:25 blackmesa mix[6011]: }, Dec 04 16:12:25 blackmesa mix[6011]: errors: [], Dec 04 16:12:25 blackmesa mix[6011]: data: #Pleroma.Web.OAuth.App<>, Dec 04 16:12:25 blackmesa mix[6011]: valid?: true Dec 04 16:12:25 blackmesa mix[6011]: > Dec 04 16:12:25 blackmesa mix[6011]: {:ok, Dec 04 16:12:25 blackmesa mix[6011]: %Pleroma.Web.OAuth.App{ Dec 04 16:12:25 blackmesa mix[6011]: __meta__: #Ecto.Schema.Metadata<:loaded, "apps">, Dec 04 16:12:25 blackmesa mix[6011]: client_id: "nt0Te5Cy6LJ_mnsKCx10jQO_BePdXLq3_ij6Ky6ipm0=", Dec 04 16:12:25 blackmesa mix[6011]: client_name: "PleromaFE_0.46968103918748183", Dec 04 16:12:25 blackmesa mix[6011]: client_secret: "[REDACTED]", Dec 04 16:12:25 blackmesa mix[6011]: id: 52, Dec 04 16:12:25 blackmesa mix[6011]: inserted_at: ~N[2018-12-04 15:12:25.417070], Dec 04 16:12:25 blackmesa mix[6011]: redirect_uris: "https://twinkaga.in/oauth-callback", Dec 04 16:12:25 blackmesa mix[6011]: scopes: "read write follow", Dec 04 16:12:25 blackmesa mix[6011]: updated_at: ~N[2018-12-04 15:12:25.417094], Dec 04 16:12:25 blackmesa mix[6011]: website: nil Dec 04 16:12:25 blackmesa mix[6011]: }} Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.419 request_id=2lmijr8g9qbh2k3s040009b1 [info] Sent 200 in 3ms Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.520 request_id=2lmijr8mhgb1tvqdmk0009bh [info] POST /oauth/token Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.523 request_id=2lmijr8mhgb1tvqdmk0009bh [info] Sent 400 in 3ms Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.661 request_id=2lmijr8uuuje25tek00009c1 [info] POST /api/account/verify_credentials.json Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.661 request_id=2lmijr8uuuje25tek00009c1 [info] Sent 403 in 106µs Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.663 request_id=2lmijr8v36g5d3f3dk0009ch [info] GET /api/statuses/friends_timeline.json Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.663 request_id=2lmijr8v36g5d3f3dk0009ch [info] Sent 403 in 69µs ``` MastodonFE and PleromaFE have both this error. I tried cleaning and recompiling deps, cleaning and recompiling Pleroma (mix clean, mix compile), I created uuid-ossp in Postgres (because when you make ecto.migrate, there was an error of insufficient privileges when creating the extension), but nothing really explains why it happens. It's the first time it's doing this error, I still can connect to my accounts.
Member

I confirm this bug. I created a brand new instance on pleroma edge.
I created a first user with mix register_user but i can't login.

16:01:33.512 [error] #PID<0.614.0> running Pleroma.Web.Endpoint (cowboy_protocol) terminated Server: scale.lord.re:80 (http) Request: POST /api/account/verify_credentials.json ** (exit) an exception was raised: ** (UndefinedFunctionError) function nil.deactivated/0 is undefined nil.deactivated() (pleroma) lib/pleroma/plugs/oauth_plug.ex:23: Pleroma.Plugs.OAuthPlug.call/2 (pleroma) lib/pleroma/web/router.ex:20: Pleroma.Web.Router.authenticated_api/2 (pleroma) lib/pleroma/web/router.ex:1: Pleroma.Web.Router.__pipe_through3__/1 (phoenix) lib/phoenix/router.ex:273: Phoenix.Router.__call__/1 (pleroma) lib/pleroma/web/endpoint.ex:1: Pleroma.Web.Endpoint.plug_builder_call/2 (pleroma) lib/pleroma/web/endpoint.ex:1: Pleroma.Web.Endpoint.call/2 (plug) lib/plug/adapters/cowboy/handler.ex:16: Plug.Adapters.Cowboy.Handler.upgrade/4

I confirm this bug. I created a brand new instance on pleroma edge. I created a first user with mix register_user but i can't login. `16:01:33.512 [error] #PID<0.614.0> running Pleroma.Web.Endpoint (cowboy_protocol) terminated Server: scale.lord.re:80 (http) Request: POST /api/account/verify_credentials.json ** (exit) an exception was raised: ** (UndefinedFunctionError) function nil.deactivated/0 is undefined nil.deactivated() (pleroma) lib/pleroma/plugs/oauth_plug.ex:23: Pleroma.Plugs.OAuthPlug.call/2 (pleroma) lib/pleroma/web/router.ex:20: Pleroma.Web.Router.authenticated_api/2 (pleroma) lib/pleroma/web/router.ex:1: Pleroma.Web.Router.__pipe_through3__/1 (phoenix) lib/phoenix/router.ex:273: Phoenix.Router.__call__/1 (pleroma) lib/pleroma/web/endpoint.ex:1: Pleroma.Web.Endpoint.plug_builder_call/2 (pleroma) lib/pleroma/web/endpoint.ex:1: Pleroma.Web.Endpoint.call/2 (plug) lib/plug/adapters/cowboy/handler.ex:16: Plug.Adapters.Cowboy.Handler.upgrade/4`
Member

I am able to relogin to twinkaga.in after logging out (even in a new session).

Logging in from a different origin doesn't work, however.

I am able to relogin to twinkaga.in after logging out (even in a new session). Logging in from a different origin doesn't work, however.
Member

Note: I get the same bug with a local frontend + chromium, firefox logs in nicely

Note: I get the same bug with a local frontend + chromium, firefox logs in nicely

different origin problems sound like csp / cors problems

different origin problems sound like csp / cors problems

@mrtino Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.520 request_id=2lmijr8mhgb1tvqdmk0009bh [info] POST /oauth/token Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.523 request_id=2lmijr8mhgb1tvqdmk0009bh [info] Sent 400 in 3ms

The problem is there somewhere, can you switch to dev mode so we can see if there is any additional output?

@mrtino ```Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.520 request_id=2lmijr8mhgb1tvqdmk0009bh [info] POST /oauth/token Dec 04 16:12:25 blackmesa mix[6011]: 16:12:25.523 request_id=2lmijr8mhgb1tvqdmk0009bh [info] Sent 400 in 3ms``` The problem is there somewhere, can you switch to dev mode so we can see if there is any additional output?
Member

The problem is due to user.info being nil:

dev:~/pleroma$ MIX_ENV=prod mix register_user kaniinitest1 kaniinitest1 nenolod+kt1@gmail.com lol [REDACTED]
03:20:14.381 [info] Retry queue disabled
03:20:14.537 [info] Gopher server disabled
dev:~/pleroma$ MIX_ENV=prod iex -S mix
Erlang/OTP 20 [erts-9.3] [source] [64-bit] [smp:1:1] [ds:1:1:10] [async-threads:10] [hipe] [kernel-poll:false]

03:20:21.406 [info] Retry queue disabled
03:20:21.533 [info] Gopher server disabled
Interactive Elixir (1.6.5) - press Ctrl+C to exit (type h() ENTER for help)
iex(1)> alias Pleroma.{User, Repo}
[Pleroma.User, Pleroma.Repo]
iex(2)> User.get_by_nickname("kaniinitest1")
%Pleroma.User{
  __meta__: #Ecto.Schema.Metadata<:loaded, "users">,
  ap_id: "https://pleroma.dereferenced.org/users/kaniinitest1",
  avatar: nil,
  bio: "lol",
  email: "nenolod+kt1@gmail.com",
  follower_address: "https://pleroma.dereferenced.org/users/kaniinitest1/followers",
  following: ["https://pleroma.dereferenced.org/users/kaniinitest1/followers"],
  id: 26943,
  info: nil,
  inserted_at: ~N[2018-12-05 03:20:15.588168],
  last_refreshed_at: nil,
  local: true,
  name: "kaniinitest1",
  nickname: "kaniinitest1",
  notifications: #Ecto.Association.NotLoaded<association :notifications is not loaded>,
  password: nil,
  password_confirmation: nil,
  password_hash: "$pbkdf2-sha512$160000$X84r.5BBjHS06YOIE.wB.A$GAUIiDsZAHnp3OzaxWuNXP1.ljxh05IDSu/uJbO.BMaJ6op0bNA.5vLW9yb0Y1qq7ZmU/0sv6FMrE.Ze4GzLWA",
  search_distance: nil,
  updated_at: ~N[2018-12-05 03:20:15.596997]
}
The problem is due to user.info being nil: ``` dev:~/pleroma$ MIX_ENV=prod mix register_user kaniinitest1 kaniinitest1 nenolod+kt1@gmail.com lol [REDACTED] 03:20:14.381 [info] Retry queue disabled 03:20:14.537 [info] Gopher server disabled dev:~/pleroma$ MIX_ENV=prod iex -S mix Erlang/OTP 20 [erts-9.3] [source] [64-bit] [smp:1:1] [ds:1:1:10] [async-threads:10] [hipe] [kernel-poll:false] 03:20:21.406 [info] Retry queue disabled 03:20:21.533 [info] Gopher server disabled Interactive Elixir (1.6.5) - press Ctrl+C to exit (type h() ENTER for help) iex(1)> alias Pleroma.{User, Repo} [Pleroma.User, Pleroma.Repo] iex(2)> User.get_by_nickname("kaniinitest1") %Pleroma.User{ __meta__: #Ecto.Schema.Metadata<:loaded, "users">, ap_id: "https://pleroma.dereferenced.org/users/kaniinitest1", avatar: nil, bio: "lol", email: "nenolod+kt1@gmail.com", follower_address: "https://pleroma.dereferenced.org/users/kaniinitest1/followers", following: ["https://pleroma.dereferenced.org/users/kaniinitest1/followers"], id: 26943, info: nil, inserted_at: ~N[2018-12-05 03:20:15.588168], last_refreshed_at: nil, local: true, name: "kaniinitest1", nickname: "kaniinitest1", notifications: #Ecto.Association.NotLoaded<association :notifications is not loaded>, password: nil, password_confirmation: nil, password_hash: "$pbkdf2-sha512$160000$X84r.5BBjHS06YOIE.wB.A$GAUIiDsZAHnp3OzaxWuNXP1.ljxh05IDSu/uJbO.BMaJ6op0bNA.5vLW9yb0Y1qq7ZmU/0sv6FMrE.Ze4GzLWA", search_distance: nil, updated_at: ~N[2018-12-05 03:20:15.596997] } ```
Member

Setting info to {} by hand makes it work:

dev:~/pleroma$ psql -U pleroma pleroma_dev
psql (10.3)
Type "help" for help.

pleroma_dev=> update users set info='{}' where nickname='kaniinitest1';
UPDATE 1
pleroma_dev=> ^D\q
dev:~/pleroma$ MIX_ENV=prod iex -S mix
Erlang/OTP 20 [erts-9.3] [source] [64-bit] [smp:1:1] [ds:1:1:10] [async-threads:10] [hipe] [kernel-poll:false]

03:28:14.553 [info] Retry queue disabled
03:28:14.682 [info] Gopher server disabled
Interactive Elixir (1.6.5) - press Ctrl+C to exit (type h() ENTER for help)
iex(1)> alias Pleroma.User
Pleroma.User
iex(2)> User.get_by_nickname("kaniinitest1")
%Pleroma.User{
  __meta__: #Ecto.Schema.Metadata<:loaded, "users">,
  ap_id: "https://pleroma.dereferenced.org/users/kaniinitest1",
  avatar: nil,
  bio: "lol",
  email: "nenolod+kt1@gmail.com",
  follower_address: "https://pleroma.dereferenced.org/users/kaniinitest1/followers",
  following: ["https://pleroma.dereferenced.org/users/kaniinitest1/followers"],
  id: 26943,
  info: %Pleroma.User.Info{
    ap_enabled: false,
    background: %{},
    banner: %{},
    blocks: [],
    deactivated: false,
    default_scope: "public",
    domain_blocks: [],
    follower_count: 0,
    hub: nil,
    id: nil,
    is_admin: false,
    is_moderator: false,
    keys: nil,
    locked: false,
    magic_key: nil,
    no_rich_text: false,
    note_count: 0,
    salmon: nil,
    settings: nil,
    source_data: %{},
    topic: nil,
    uri: nil
  },
  inserted_at: ~N[2018-12-05 03:20:15.588168],
  last_refreshed_at: nil,
  local: true,
  name: "kaniinitest1",
  nickname: "kaniinitest1",
  notifications: #Ecto.Association.NotLoaded<association :notifications is not loaded>,
  password: nil,
  password_confirmation: nil,
  password_hash: "$pbkdf2-sha512$160000$X84r.5BBjHS06YOIE.wB.A$GAUIiDsZAHnp3OzaxWuNXP1.ljxh05IDSu/uJbO.BMaJ6op0bNA.5vLW9yb0Y1qq7ZmU/0sv6FMrE.Ze4GzLWA",
  search_distance: nil,
  updated_at: ~N[2018-12-05 03:20:15.596997]
}
Setting info to `{}` by hand makes it work: ``` dev:~/pleroma$ psql -U pleroma pleroma_dev psql (10.3) Type "help" for help. pleroma_dev=> update users set info='{}' where nickname='kaniinitest1'; UPDATE 1 pleroma_dev=> ^D\q dev:~/pleroma$ MIX_ENV=prod iex -S mix Erlang/OTP 20 [erts-9.3] [source] [64-bit] [smp:1:1] [ds:1:1:10] [async-threads:10] [hipe] [kernel-poll:false] 03:28:14.553 [info] Retry queue disabled 03:28:14.682 [info] Gopher server disabled Interactive Elixir (1.6.5) - press Ctrl+C to exit (type h() ENTER for help) iex(1)> alias Pleroma.User Pleroma.User iex(2)> User.get_by_nickname("kaniinitest1") %Pleroma.User{ __meta__: #Ecto.Schema.Metadata<:loaded, "users">, ap_id: "https://pleroma.dereferenced.org/users/kaniinitest1", avatar: nil, bio: "lol", email: "nenolod+kt1@gmail.com", follower_address: "https://pleroma.dereferenced.org/users/kaniinitest1/followers", following: ["https://pleroma.dereferenced.org/users/kaniinitest1/followers"], id: 26943, info: %Pleroma.User.Info{ ap_enabled: false, background: %{}, banner: %{}, blocks: [], deactivated: false, default_scope: "public", domain_blocks: [], follower_count: 0, hub: nil, id: nil, is_admin: false, is_moderator: false, keys: nil, locked: false, magic_key: nil, no_rich_text: false, note_count: 0, salmon: nil, settings: nil, source_data: %{}, topic: nil, uri: nil }, inserted_at: ~N[2018-12-05 03:20:15.588168], last_refreshed_at: nil, local: true, name: "kaniinitest1", nickname: "kaniinitest1", notifications: #Ecto.Association.NotLoaded<association :notifications is not loaded>, password: nil, password_confirmation: nil, password_hash: "$pbkdf2-sha512$160000$X84r.5BBjHS06YOIE.wB.A$GAUIiDsZAHnp3OzaxWuNXP1.ljxh05IDSu/uJbO.BMaJ6op0bNA.5vLW9yb0Y1qq7ZmU/0sv6FMrE.Ze4GzLWA", search_distance: nil, updated_at: ~N[2018-12-05 03:20:15.596997] } ```
Member

fixed in #3893

fixed in #3893
Sign in to join this conversation.
No milestone
No project
No assignees
5 participants
Notifications
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference
pleroma/pleroma#408
No description provided.