Crash when attempting to remove user from an organization #5070

@lunny commented on GitHub (Mar 17, 2020):

For non single user, we recommand not to use sqlite.

@lunny commented on GitHub (Mar 17, 2020): For non single user, we recommand not to use sqlite.

GiteaMirror commented

@gilesorr commented on GitHub (Mar 19, 2020):

why not sqlite? It's fast and can handle a large DB and a lot of transactions (assume I'm aware of potential multi-user security issues)
this definitely seems like a bug: does your message mean that because it's occurring with sqlite you won't fix it?
is it known that this bug does NOT occur with the other supported databases?

@gilesorr commented on GitHub (Mar 19, 2020): - why not sqlite? It's fast and can handle a large DB and a lot of transactions (assume I'm aware of potential multi-user security issues) - this definitely seems like a bug: does your message mean that because it's occurring with sqlite you won't fix it? - is it known that this bug does NOT occur with the other supported databases?

GiteaMirror commented

@jolheiser commented on GitHub (Mar 19, 2020):

Can you send some logs? If you are comfortable sifting yourself, you can look for errors around when the user is removed.
No need to send the full log, but as much as you are comfortable with would be potentially beneficial.

@jolheiser commented on GitHub (Mar 19, 2020): Can you send some logs? If you are comfortable sifting yourself, you can look for errors around when the user is removed. No need to send the full log, but as much as you are comfortable with would be potentially beneficial.

GiteaMirror commented

@gilesorr commented on GitHub (Mar 19, 2020):

Here's the log of the event, from when I pressed the "Remove" button until I was forced to shut down the gitea service.

2020/03/19 21:31:55 .../xorm/session_raw.go:78:queryRows() [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`, `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` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{1} - took: 217.18µs
2020/03/19 21:31:55 .../xorm/session_raw.go:78:queryRows() [I] [SQL] SELECT count(*) FROM `notification` WHERE (user_id = ?) AND (status = ?) []interface {}{1, 0x1} - took: 110.909µs
2020/03/19 21:31:55 .../xorm/session_raw.go:78:queryRows() [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`, `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` FROM `user` WHERE `lower_name`=? LIMIT 1 []interface {}{"tpl"} - took: 189.369µs
2020/03/19 21:31:55 .../xorm/session_raw.go:78:queryRows() [I] [SQL] SELECT `id`, `org_id`, `lower_name`, `name`, `description`, `authorize`, `num_repos`, `num_members`, `includes_all_repositories`, `can_create_org_repo` FROM `team` WHERE (org_id=?) ORDER BY CASE WHEN name LIKE 'Owners' THEN '' ELSE name END []interface {}{34} - took: 125.2µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `uid`, `org_id`, `is_public` FROM `org_user` WHERE (uid=?) AND (org_id=?) LIMIT 1 []interface {}{29, 34} - took: 58.135µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [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`, `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` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{34} - took: 210.941µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `org_id`, `lower_name`, `name`, `description`, `authorize`, `num_repos`, `num_members`, `includes_all_repositories`, `can_create_org_repo` FROM `team` WHERE `org_id`=? AND `lower_name`=? LIMIT 1 []interface {}{34, "owners"} - took: 131.983µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT * FROM `team_user` WHERE (org_id=?) AND (team_id=?) AND (uid=?) LIMIT 1 []interface {}{34, 2, 29} - took: 73.476µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `org_user` WHERE `id`=? AND `uid`=? AND `org_id`=? AND `id`=? []interface {}{5, 29, 34, 5} - took: 401.22µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `user` SET num_members=num_members-1 WHERE id=? []interface {}{34} - took: 109.243µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `team`.`id` FROM `team` INNER JOIN team_user ON `team_user`.team_id = team.id WHERE (`team_user`.org_id = ?) AND (`team_user`.uid = ?) []interface {}{34, 29} - took: 84.575µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `repository`.`id` FROM `repository` INNER JOIN team_repo ON `team_repo`.repo_id=`repository`.id WHERE ((`repository`.is_private=? AND `repository`.owner_id=?) OR team_repo.team_id IN (?)) GROUP BY `repository`.id,`repository`.updated_unix ORDER BY updated_unix DESC LIMIT 3 []interface {}{false, 34, 3} - took: 93.401µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `mode` FROM `watch` WHERE `user_id`=? AND `repo_id`=? LIMIT 1 []interface {}{29, 20} - took: 54.937µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `watch` WHERE `id`=? []interface {}{68} - took: 88.737µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `repository` SET num_watches = num_watches + ? WHERE id = ? []interface {}{-1, 20} - took: 83.826µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `mode` FROM `watch` WHERE `user_id`=? AND `repo_id`=? LIMIT 1 []interface {}{29, 8} - took: 47.92µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `watch` WHERE `id`=? []interface {}{13} - took: 59.535µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `repository` SET num_watches = num_watches + ? WHERE id = ? []interface {}{-1, 8} - took: 43.511µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `mode` FROM `watch` WHERE `user_id`=? AND `repo_id`=? LIMIT 1 []interface {}{29, 7} - took: 31.028µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `watch` WHERE `id`=? []interface {}{15} - took: 77.708µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `repository` SET num_watches = num_watches + ? WHERE id = ? []interface {}{-1, 7} - took: 91.597µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `access` WHERE (user_id = ?) AND `repo_id` IN (?,?,?) []interface {}{29, 20, 8, 7} - took: 116.117µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT * FROM `team` INNER JOIN team_user ON team_user.team_id = team.id WHERE (team.org_id = ?) AND (team_user.uid=?) []interface {}{34, 29} - took: 79.945µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT * FROM `team_user` WHERE (org_id=?) AND (team_id=?) AND (uid=?) LIMIT 1 []interface {}{34, 3, 29} - took: 55.312µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT * FROM `repository` INNER JOIN team_repo ON repository.id = team_repo.repo_id WHERE (team_repo.team_id=?) ORDER BY repository.name []interface {}{3} - took: 289.094µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `team_user` WHERE `org_id`=? AND `team_id`=? AND `uid`=? []interface {}{34, 3, 29} - took: 117.46µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `team` SET `num_members` = ? WHERE `id`=? []interface {}{3, 3} - took: 50.818µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `repo_id`, `user_id`, `mode` FROM `collaboration` WHERE `repo_id`=? AND `user_id`=? LIMIT 1 []interface {}{7, 29} - took: 64.291µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [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`, `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` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{34} - took: 87.459µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT * FROM `team` INNER JOIN team_repo ON team_repo.team_id = team.id INNER JOIN team_user ON team_user.team_id = team.id WHERE (team.org_id = ?) AND (team_repo.repo_id=?) AND (team_user.uid=?) []interface {}{34, 7, 29} - took: 276.33µs
2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `access` WHERE `user_id`=? AND `repo_id`=? []interface {}{29, 7} - took: 30.581µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [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`, `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` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{29} - took: 81.868µs
2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `repo_id`, `user_id`, `mode` FROM `collaboration` WHERE `repo_id`=? AND `user_id`=? LIMIT 1 []interface {}{7, 29} - took: 54.149µs
2020/03/19 21:31:55 .../xorm/session_raw.go:78:queryRows() [I] [SQL] SELECT * FROM `org_user` WHERE (uid=?) AND (org_id=?) LIMIT 1 []interface {}{29, 34} - took: 47.718µs
2020/03/19 21:33:19 ...eful/manager_unix.go:133:handleSignals() [W] PID 31257. Received SIGTERM. Shutting down...
2020/03/19 21:33:19 ...eful/server_hooks.go:47:doShutdown() [I] PID: 31257 Listener (/run/gitea/gitea.socket) closed.
2020/03/19 21:33:19 ...rvices/pull/check.go:214:TestPullRequests() [I] PID: 31257 Pull Request testing shutdown

@gilesorr commented on GitHub (Mar 19, 2020): Here's the log of the event, from when I pressed the "Remove" button until I was forced to shut down the gitea service. ``` 2020/03/19 21:31:55 .../xorm/session_raw.go:78:queryRows() [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`, `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` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{1} - took: 217.18µs 2020/03/19 21:31:55 .../xorm/session_raw.go:78:queryRows() [I] [SQL] SELECT count(*) FROM `notification` WHERE (user_id = ?) AND (status = ?) []interface {}{1, 0x1} - took: 110.909µs 2020/03/19 21:31:55 .../xorm/session_raw.go:78:queryRows() [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`, `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` FROM `user` WHERE `lower_name`=? LIMIT 1 []interface {}{"tpl"} - took: 189.369µs 2020/03/19 21:31:55 .../xorm/session_raw.go:78:queryRows() [I] [SQL] SELECT `id`, `org_id`, `lower_name`, `name`, `description`, `authorize`, `num_repos`, `num_members`, `includes_all_repositories`, `can_create_org_repo` FROM `team` WHERE (org_id=?) ORDER BY CASE WHEN name LIKE 'Owners' THEN '' ELSE name END []interface {}{34} - took: 125.2µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `uid`, `org_id`, `is_public` FROM `org_user` WHERE (uid=?) AND (org_id=?) LIMIT 1 []interface {}{29, 34} - took: 58.135µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [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`, `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` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{34} - took: 210.941µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `org_id`, `lower_name`, `name`, `description`, `authorize`, `num_repos`, `num_members`, `includes_all_repositories`, `can_create_org_repo` FROM `team` WHERE `org_id`=? AND `lower_name`=? LIMIT 1 []interface {}{34, "owners"} - took: 131.983µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT * FROM `team_user` WHERE (org_id=?) AND (team_id=?) AND (uid=?) LIMIT 1 []interface {}{34, 2, 29} - took: 73.476µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `org_user` WHERE `id`=? AND `uid`=? AND `org_id`=? AND `id`=? []interface {}{5, 29, 34, 5} - took: 401.22µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `user` SET num_members=num_members-1 WHERE id=? []interface {}{34} - took: 109.243µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `team`.`id` FROM `team` INNER JOIN team_user ON `team_user`.team_id = team.id WHERE (`team_user`.org_id = ?) AND (`team_user`.uid = ?) []interface {}{34, 29} - took: 84.575µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `repository`.`id` FROM `repository` INNER JOIN team_repo ON `team_repo`.repo_id=`repository`.id WHERE ((`repository`.is_private=? AND `repository`.owner_id=?) OR team_repo.team_id IN (?)) GROUP BY `repository`.id,`repository`.updated_unix ORDER BY updated_unix DESC LIMIT 3 []interface {}{false, 34, 3} - took: 93.401µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `mode` FROM `watch` WHERE `user_id`=? AND `repo_id`=? LIMIT 1 []interface {}{29, 20} - took: 54.937µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `watch` WHERE `id`=? []interface {}{68} - took: 88.737µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `repository` SET num_watches = num_watches + ? WHERE id = ? []interface {}{-1, 20} - took: 83.826µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `mode` FROM `watch` WHERE `user_id`=? AND `repo_id`=? LIMIT 1 []interface {}{29, 8} - took: 47.92µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `watch` WHERE `id`=? []interface {}{13} - took: 59.535µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `repository` SET num_watches = num_watches + ? WHERE id = ? []interface {}{-1, 8} - took: 43.511µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `user_id`, `repo_id`, `mode` FROM `watch` WHERE `user_id`=? AND `repo_id`=? LIMIT 1 []interface {}{29, 7} - took: 31.028µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `watch` WHERE `id`=? []interface {}{15} - took: 77.708µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `repository` SET num_watches = num_watches + ? WHERE id = ? []interface {}{-1, 7} - took: 91.597µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `access` WHERE (user_id = ?) AND `repo_id` IN (?,?,?) []interface {}{29, 20, 8, 7} - took: 116.117µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT * FROM `team` INNER JOIN team_user ON team_user.team_id = team.id WHERE (team.org_id = ?) AND (team_user.uid=?) []interface {}{34, 29} - took: 79.945µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT * FROM `team_user` WHERE (org_id=?) AND (team_id=?) AND (uid=?) LIMIT 1 []interface {}{34, 3, 29} - took: 55.312µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT * FROM `repository` INNER JOIN team_repo ON repository.id = team_repo.repo_id WHERE (team_repo.team_id=?) ORDER BY repository.name []interface {}{3} - took: 289.094µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `team_user` WHERE `org_id`=? AND `team_id`=? AND `uid`=? []interface {}{34, 3, 29} - took: 117.46µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `team` SET `num_members` = ? WHERE `id`=? []interface {}{3, 3} - took: 50.818µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `repo_id`, `user_id`, `mode` FROM `collaboration` WHERE `repo_id`=? AND `user_id`=? LIMIT 1 []interface {}{7, 29} - took: 64.291µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [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`, `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` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{34} - took: 87.459µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT * FROM `team` INNER JOIN team_repo ON team_repo.team_id = team.id INNER JOIN team_user ON team_user.team_id = team.id WHERE (team.org_id = ?) AND (team_repo.repo_id=?) AND (team_user.uid=?) []interface {}{34, 7, 29} - took: 276.33µs 2020/03/19 21:31:55 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `access` WHERE `user_id`=? AND `repo_id`=? []interface {}{29, 7} - took: 30.581µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [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`, `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` FROM `user` WHERE `id`=? LIMIT 1 []interface {}{29} - took: 81.868µs 2020/03/19 21:31:55 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `repo_id`, `user_id`, `mode` FROM `collaboration` WHERE `repo_id`=? AND `user_id`=? LIMIT 1 []interface {}{7, 29} - took: 54.149µs 2020/03/19 21:31:55 .../xorm/session_raw.go:78:queryRows() [I] [SQL] SELECT * FROM `org_user` WHERE (uid=?) AND (org_id=?) LIMIT 1 []interface {}{29, 34} - took: 47.718µs 2020/03/19 21:33:19 ...eful/manager_unix.go:133:handleSignals() [W] PID 31257. Received SIGTERM. Shutting down... 2020/03/19 21:33:19 ...eful/server_hooks.go:47:doShutdown() [I] PID: 31257 Listener (/run/gitea/gitea.socket) closed. 2020/03/19 21:33:19 ...rvices/pull/check.go:214:TestPullRequests() [I] PID: 31257 Pull Request testing shutdown ```

GiteaMirror commented

@gilesorr commented on GitHub (Mar 20, 2020):

Let me know if there's anything else I can help with. Thanks.

@gilesorr commented on GitHub (Mar 20, 2020): Let me know if there's anything else I can help with. Thanks.

GiteaMirror commented

@lunny commented on GitHub (Mar 20, 2020):

@gilesorr I don't mean we will not try to fix the problem.

Because sqlite itself has some limitation when many go routines read/write the tables at the same time. For a peronsal use, it should be fast. But when there are more users, it will be slow if some users use it at the same time.

@lunny commented on GitHub (Mar 20, 2020): @gilesorr I don't mean we will not try to fix the problem. Because sqlite itself has some limitation when many go routines read/write the tables at the same time. For a peronsal use, it should be fast. But when there are more users, it will be slow if some users use it at the same time.

GiteaMirror commented

@gilesorr commented on GitHub (Mar 20, 2020):

As mentioned, we have only a small number of users - and so far, gitea hasn't been heavily used. Duly noted though: when we start using it more, I'll keep an eye out for slow-downs and will consider a move to PostgreSQL if that happens. Thanks.

@gilesorr commented on GitHub (Mar 20, 2020): As mentioned, we have only a small number of users - and so far, gitea hasn't been heavily used. Duly noted though: when we start using it more, I'll keep an eye out for slow-downs and will consider a move to PostgreSQL if that happens. Thanks.

GiteaMirror commented

@zeripath commented on GitHub (Mar 24, 2020):

This is probably already mitigated on master as we now use begin immediate for sqlite

@zeripath commented on GitHub (Mar 24, 2020): This is probably already mitigated on master as we now use begin immediate for sqlite

GiteaMirror commented

https://github.com/go-gitea/gitea/blob/v1.11.3/modules/setting/database.go#L127

@guillep2k commented on GitHub (Mar 24, 2020):

@zeripath that was my first thought, but it looks like the change is already present on 1.11.3:

I'm thinking on it... I think it's possible there's still some scenarios that can't be covered by this if two different goroutines open multiple transactions to perform one operation (e.g. implicit transactions to perform SELECT operations and later on an explicit transaction for INSERT, etc.). I can't picture that scenario myself, though.

@gilesorr To gather more info, it would be great if you could create a dump of Gitea's process at the moment it's frozen (you'd need go and delve installed for that):

# Replace 24006 for your current Gitea PID
dlv attach 24006
Type 'help' for list of commands.
(dlv) grs -t
  Goroutine 1 - User: /usr/local/go/src/runtime/netpoll.go:184 internal/poll.runtime_pollWait (0x432f65)
         0  0x0000000000438c00 in runtime.gopark
             at /usr/local/go/src/runtime/proc.go:305
         1  0x000000000043399a in runtime.netpollblock
             at /usr/local/go/src/runtime/netpoll.go:397
         2  0x0000000000432f65 in internal/poll.runtime_pollWait
             at /usr/local/go/src/runtime/netpoll.go:184
         3  0x00000000004d30e5 in internal/poll.(*pollDesc).wait
[... etc ...]

@guillep2k commented on GitHub (Mar 24, 2020): @zeripath that was my first thought, but it looks like the change is already present on 1.11.3: https://github.com/go-gitea/gitea/blob/v1.11.3/modules/setting/database.go#L127 I'm thinking on it... I think it's possible there's still some scenarios that can't be covered by this if two different goroutines open multiple transactions to perform one operation (e.g. implicit transactions to perform `SELECT` operations and later on an explicit transaction for `INSERT`, etc.). I can't picture that scenario myself, though. @gilesorr To gather more info, it would be great if you could create a dump of Gitea's process at the moment it's frozen (you'd need `go` and `delve` installed for that): ``` # Replace 24006 for your current Gitea PID dlv attach 24006 Type 'help' for list of commands. (dlv) grs -t Goroutine 1 - User: /usr/local/go/src/runtime/netpoll.go:184 internal/poll.runtime_pollWait (0x432f65) 0 0x0000000000438c00 in runtime.gopark at /usr/local/go/src/runtime/proc.go:305 1 0x000000000043399a in runtime.netpollblock at /usr/local/go/src/runtime/netpoll.go:397 2 0x0000000000432f65 in internal/poll.runtime_pollWait at /usr/local/go/src/runtime/netpoll.go:184 3 0x00000000004d30e5 in internal/poll.(*pollDesc).wait [... etc ...] ```

GiteaMirror commented

@edoger commented on GitHub (Mar 25, 2020):

I had the same problem.

@edoger commented on GitHub (Mar 25, 2020): I had the same problem.

GiteaMirror commented

@gilesorr commented on GitHub (Mar 25, 2020):

Not a Go expert, please accept my apologies if this has been done incorrectly.

I created two delve dumps - I thought I did three, but one got lost. The first is before the deliberately-caused crash ("51 goroutines"), the second is a couple minutes after ("71 goroutines"). The one I lost was about 30 seconds after the crash: it said "58 goroutines" (that's all I've got for you on that one). I tried a minute later again, and it was still at 71 so I killed the process ...

BEFORE:
typescript.before.txt

AFTER:
typescript.after.txt

@gilesorr commented on GitHub (Mar 25, 2020): Not a Go expert, please accept my apologies if this has been done incorrectly. I created two delve dumps - I thought I did three, but one got lost. The first is before the deliberately-caused crash ("51 goroutines"), the second is a couple minutes after ("71 goroutines"). The one I lost was about 30 seconds after the crash: it said "58 goroutines" (that's all I've got for you on that one). I tried a minute later again, and it was still at 71 so I killed the process ... BEFORE: [typescript.before.txt](https://github.com/go-gitea/gitea/files/4383768/typescript.before.txt) AFTER: [typescript.after.txt](https://github.com/go-gitea/gitea/files/4383770/typescript.after.txt)

GiteaMirror commented