Server freezes when transferring the ownership

• Gitea version (or commit ref): v1.11.1
• Git version: 2.20.1
• Operating system: Debian 10.3
• Database (use [x]):
  • PostgreSQL
  • MySQL
  • MSSQL
  • SQLite
• Can you reproduce the bug at https://try.gitea.io:
  • Yes (provide example URL)
  • No
  • Not relevant
• Log gist:
  When I restart the frozen server:

2020/03/01 08:52:10 ...eful/manager_unix.go:133:handleSignals() [W] PID 10968. Received SIGTERM. Shutting down...
2020/03/01 08:52:10 ...eful/server_hooks.go:47:doShutdown() [I] PID: 10968 Listener ([::]:3000) closed.
2020/03/01 08:52:10 ...rvices/pull/check.go:214:TestPullRequests() [I] PID: 10968 Pull Request testing shutdown
2020/03/01 08:52:10 .../ssh/ssh_graceful.go:21:listen() [I] SSH Listener: :23000 Closed
2020/03/01 08:52:10 ...eful/server_hooks.go:47:doShutdown() [I] PID: 10968 Listener ([::]:23000) closed.
2020/03/01 08:53:10 .../graceful/manager.go:184:doHammerTime() [W] Setting Hammer condition
2020/03/01 08:53:10 ...eful/server_hooks.go:64:doHammer() [W] Forcefully shutting down parent
2020/03/01 08:53:10 cmd/web.go:206:runWeb() [I] HTTP Listener: 0.0.0.0:3000 Closed
2020/03/01 08:53:10 routers/user/home.go:132:Dashboard() [E] GetMirrorRepositories: Graceful Manager called Hammer
2020/03/01 08:53:10 ...ters/repo/setting.go:382:SettingsPost() [E] TransferOwnership: GetTeams: Graceful Manager called Hammer
2020/03/01 08:53:10 ...les/context/panic.go:35:1() [E] PANIC:: sync: negative WaitGroup counter
  /usr/local/go/src/sync/waitgroup.go:74 (0x485ee8)
  /usr/local/go/src/sync/waitgroup.go:99 (0x106ac52)
  /go/src/code.gitea.io/gitea/modules/graceful/server.go:253 (0x106ac36)
  /usr/local/go/src/net/http/server.go:387 (0x74af83)
  /usr/local/go/src/bufio/bufio.go:625 (0x5845c3)
  /usr/local/go/src/net/http/server.go:1572 (0x751169)
  /usr/local/go/src/net/http/server.go:1541 (0x750df5)
  /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/response_writer.go:69 (0x9eb136)
  /usr/local/go/src/bytes/buffer.go:239 (0x50c854)
  /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/render.go:575 (0x9ea19a)
  /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/render.go:586 (0x9ea3fa)
  /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:157 (0x9e18a8)
  /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:167 (0xfe9ace)
  /go/src/code.gitea.io/gitea/modules/context/context.go:140 (0xfe9a7a)
  /go/src/code.gitea.io/gitea/modules/context/context.go:186 (0xfea146)
  /go/src/code.gitea.io/gitea/modules/context/context.go:174 (0x16d32e9)
  /go/src/code.gitea.io/gitea/routers/repo/setting.go:382 (0x16d32b9)
  /usr/local/go/src/reflect/value.go:460 (0x497625)
  /usr/local/go/src/reflect/value.go:321 (0x496de3)
  /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:177 (0x9b0829)
  /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:137 (0x9b01d9)
  /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:121 (0x9e13a8)

Description

Today I encountered a strange bug. When I transfer a mirror repository, the server freezes until I manually restart it.
I checked the console and log and I don't see any error or warning.
When I re-migrated the same repository from Github and try to transfer it, it succeeded. But the problem with the old repository persisted.

Screenshots

[lafriks]

@zeripath could be related to graceful stop

[zeripath]

I suspect that is likely due to the (already fixed in master and release/v1.11) critical issue with deadlock when growing worker pools.

Either:

1. Set the following in the app.ini until 1.11.2 is released:

[queue]
BLOCK_TIMEOUT=0

2. Upgrade to the release/v1.11 branch
3. Upgrade to the master branch.

We have to release v1.11.2 soon as we are getting more and more of these essentially duplicate issues.

1. Set the following in the app.ini until 1.11.2 is released:

[queue]
BLOCK_TIMEOUT=0

I will test it when 1.11.2 is released.

[lafriks]

Closing as fixed, please reopen if v1.11.2 does not fix it

[ngugcx]

Still encounter server freeze problem with v1.11.3 when transferring ownership.
No errors found in the log.

[zeripath]

I suspect that this is because there is a deadlock being caused. It should be fixed in 1.12 due to us now using BEGIN IMMEDIATE for SQLite. Could you check on Master to see if it still happens. If it does not we can close this properly.

I couldn't reproduce the problem in the same repository with v1.11.2.

[zeripath]

It will be an intermittent issue depending on if something locks a table in the intervening period.

[ngugcx]

My environment:
Hardware: Virtualbox vm, 2g ram, 1 core.
OS: Ubuntu 18.04
Database: default sqlite
Gitea version: docker container, gitea/gitea:1.11.3, gitea/gitea:1.11.2, then gitrea/gitea:latest
Repo to transfer: There is only one repo, which has about 10,000 commits and size of 20MB.

I transferred the repo from one organization to another organization.
All failed with no errors in both container log and gitea log. The web page timeouted finally, and couldn't recover until restarted.

docker container log:

[Macaron] [Static] Serving /vendor/plugins/highlight/highlight.pack.js
[Macaron] 2020-03-11 23:25:04: Completed GET /vendor/plugins/highlight/highlight.pack.js 200 OK in 39.162677ms
[Macaron] 2020-03-11 23:25:08: Started GET /TermOld/openssh-portable/settings for 192.168.123.191
[Macaron] 2020-03-11 23:25:08: Completed GET /TermOld/openssh-portable/settings 200 OK in 63.470745ms
[Macaron] 2020-03-11 23:25:08: Started GET /user/avatar/ngugcx/-1 for 192.168.123.191
[Macaron] 2020-03-11 23:25:08: Completed GET /user/avatar/ngugcx/-1 302 Found in 3.634981ms
[Macaron] 2020-03-11 23:25:18: Started POST /TermOld/openssh-portable/settings for 192.168.123.191

gitea log:

2020/03/11 23:25:18 .../xorm/session_raw.go:78:queryRows() [I] [SQL] SELECT `id`, `uid`, `repo_id` FROM `star` WHERE `uid`=? AND `repo_id`=? LIMIT 1 []interface {}{1, 1} - took: 34.678µs
2020/03/11 23:25:18 .../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!=?) AND `lower_name`=? LIMIT 1 []interface {}{0, "term"} - took: 213.302µs
2020/03/11 23:25:18 .../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 {}{"term"} - took: 154.364µs
2020/03/11 23:25:18 .../xorm/session_raw.go:78:queryRows() [I] [SQL] SELECT `id`, `owner_id`, `lower_name`, `name`, `description`, `website`, `original_service_type`, `original_url`, `default_branch`, `num_watches`, `num_stars`, `num_forks`, `num_issues`, `num_closed_issues`, `num_pulls`, `num_closed_pulls`, `num_milestones`, `num_closed_milestones`, `is_private`, `is_empty`, `is_archived`, `is_mirror`, `status`, `is_fork`, `fork_id`, `is_template`, `template_id`, `size`, `is_fsck_enabled`, `close_issues_via_commit_in_any_branch`, `topics`, `avatar`, `created_unix`, `updated_unix` FROM `repository` WHERE `owner_id`=? AND `lower_name`=? LIMIT 1 []interface {}{2, "openssh-portable"} - took: 118.892µs
2020/03/11 23:25:18 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `repository` SET `owner_id` = ?, `lower_name` = ?, `name` = ?, `default_branch` = ?, `num_watches` = ?, `size` = ?, `updated_unix` = ? WHERE `id`=? []interface {}{2, "openssh-portable", "openssh-portable", "latestw_all_term", 1, 20964322, 1583969118, 1} - took: 362.932µs
2020/03/11 23:25:18 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `repo_id`, `user_id`, `mode` FROM `collaboration` WHERE `repo_id`=? []interface {}{1} - took: 36.948µs
2020/03/11 23:25:18 .../xorm/session_raw.go:85:queryRows() [I] [SQL] SELECT `id`, `org_id`, `team_id`, `repo_id` FROM `team_repo` WHERE `org_id`=? AND `repo_id`=? []interface {}{3, 1} - took: 37.199µs
2020/03/11 23:25:18 .../xorm/session_raw.go:180:exec() [I] [SQL] DELETE FROM `team_repo` WHERE `org_id`=? AND `repo_id`=? []interface {}{3, 1} - took: 90.855µs
2020/03/11 23:25:18 .../xorm/session_raw.go:180:exec() [I] [SQL] UPDATE `team` SET `num_repos` = `num_repos` - ? WHERE `id` IN (?) []interface {}{1, 2} - took: 55.383µs
2020/03/11 23:25:18 .../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 {}{2} - took: 156.667µs

[ngugcx]

docker-compose config:

version: "3"
  
networks:
  gitea:
    external: false

services:
  server:
    image: gitea/gitea:latest
    environment:
      - USER_UID=1000
      - USER_GID=1000
    restart: always
    networks:
      - gitea
    volumes:
      - /home/test/gitea:/data
      - /etc/timezone:/etc/timezone:ro
      - /etc/localtime:/etc/localtime:ro
    ports:
      - "3000:3000"
      - "222:22"

[ngugcx]

Tried with a small repo with only 46 commits and size of 155KB, nothing different happened.

[guillep2k]

@ngugcx We think it's a locking problem that surfaced after we moved a lot of code to background. If it is in fact that problem, it will be fixed by #10368. Unfortunately, there's no workaround for it other than:

• Install the current development version from master (it can have other bugs, though).
• Compile a patched version of Gitea 1.11.3 yourself after applying the modifications from Fix SQLite concurrency problems by using BEGIN IMMEDIATE #10368. In particular, this line.
• Usea different database engine (MariaDB, PostgreSQL, SQL Server).