gitea: After upgrading to 1.13.0, can no longer login

OK, let’s go through and find the ultimate place that calls and causes this log and think about what we can do to get some more information - or understanding.

[Macaron] 2020-12-03 22:12:20: Started POST /user/login for 10.42.0.1

Comes from:

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/routers/routes/routes.go#L106

and matches:

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/routers/routes/routes.go#L366

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/routers/user/auth.go#L151-L232

Now let’s check the SQL

2020/12/03 22:12:20 ...m.io/xorm/core/db.go:286:afterProcess() [I] [SQL] SELECT "id", "type", "name", "is_actived", "is_sync_enabled", "cfg", "created_unix", "updated_unix" FROM "login_source" WHERE (is_actived = $1 and type = $2) [true 6] - 795.229µs
2020/12/03 22:12:20 ...m.io/xorm/core/db.go:286:afterProcess() [I] [SQL] SELECT "id", "type", "name", "is_actived", "is_sync_enabled", "cfg", "created_unix", "updated_unix" FROM "login_source" WHERE (is_actived = $1 and type = $2) [true 7] - 579.519µs

are caused by:

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/routers/user/auth.go#L155

So we get in to the meat of this function. Which is performed in:

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/routers/user/auth.go#L173

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/models/login_source.go#L734-L819

The next SQL emitted :

2020/12/03 22:12:20 ...m.io/xorm/core/db.go:286:afterProcess() [I] [SQL] SELECT "id", "lower_name", "name", "full_name", "email", "keep_email_private", "email_notifications_preference", "passwd", "passwd_hash_algo", "must_change_password", "login_type", "login_source", "login_name", "type", "location", "website", "rands", "salt", "language", "description", "created_unix", "updated_unix", "last_login_unix", "last_repo_visibility", "max_repo_creation", "is_active", "is_admin", "is_restricted", "allow_git_hook", "allow_import_local", "allow_create_organization", "prohibit_login", "avatar", "avatar_email", "use_custom_avatar", "num_followers", "num_following", "num_stars", "num_repos", "num_teams", "num_members", "visibility", "repo_admin_change_team_access", "diff_view_style", "theme", "keep_activity_private" FROM "user" WHERE "lower_name"=$1 LIMIT 1 [sseneca] - 860.604µs

is caused by:

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/models/login_source.go#L758

So what is the result of this query? (You may need to change it slightly to match postgreSQL variant.)

Then we get no logs but:

[Macaron] 2020-12-03 22:12:20: Completed POST /user/login 200 OK in 29.759793ms
2020/12/03 22:12:20 routers/user/auth.go:177:SignInPost() [I] Failed authentication attempt for sseneca from 10.42.0.1

The first of which is:

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/routers/routes/routes.go#L112

and the counterpart of the first log. But the second bit comes from:

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/routers/user/auth.go#L177’

Now that implies that we have received a models.ErrUserNotExist{}

How do we get a models.ErrUserNotExist?

First of all. Let’s assume that

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/models/login_source.go#L758

returned hasUser := true - You can check this and should have checked the result of the query that this is associated with already. What is the result of that query?

To obtain a models.ErrUserNotExist if hasUser == true we have two options:

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/models/login_source.go#L764-L765

(this is the most likely path)

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/models/login_source.go#L766

The most likely problem is that this fails and interestingly if we look at the line below it we get a hint as to what might really be the problem:

https://github.com/go-gitea/gitea/blob/e39ed0b1d98b312c9986969f77acad404748e004/models/login_source.go#L769

I recall on 1.13 we changed the default hashing algorithm to argon2. Is it possible that hashing algorithm is detected incorrectly for postgres? The presumption was that the default would have been stored in the database at the time of insertion and was previously pbkdf2.

I’m gonna stop here because I bet that that is the issue.

Could the issue be, that passwd_hash_algo is not updated here when the password is changed? https://github.com/go-gitea/gitea/blob/f8e9a3df40e34945acb5c82ee9e4342b9d8f4aaf/routers/user/setting/account.go#L71

I don’t have time to debug things but the workaround posted by @luhahn worked for me. Now I can login again after changing my password with the other admin account. I checked the DB and the password hash algorithm has also been updated:

gitea=> SELECT "lower_name", "passwd_hash_algo" FROM "user";
 lower_name | passwd_hash_algo 
------------+------------------
 jonnobrow  | argon2
 sseneca    | argon2
(2 rows)

Well, I deleted the admin user via the gitea cli inside my container and created it again. Which seems to work even after reinstalling the Chart. However it is now required to set the following even for admin accounts, if you don’t want to change the password after creation:

--must-change-password=false

# full command
gitea admin create-user --username  myAdmin --password 'myPassword123 --email my@admin.com --admin --must-change-password=false 

Edit: you can also create an additional admin, if you don’t want to delete the old one

Well I’m sure I need to adjust some stuff on the init container for the helm chart. So I also created an issue there. At least the admin creation changed.

However since this also affects the downloaded binary we should not close this issue here. If I find something useful I will also post it here.

I’m confused. Both @birkb and @antoine2tt are facing this same bug, and neither use the Helm chart. Why is this bug being tracked there?