Gitea: Server freezes when transferring the ownership

[yasuokav]

• Gitea version (or commit ref): v1.11.1
• Git version: 2.20.1
• Operating system: Debian 10.3
• Database (use [x]):
  
  
  
  • [ ] PostgreSQL
  
  
  • [ ] MySQL
  
  
  • [ ] MSSQL
  
  
  • [x] SQLite
  
  
• Can you reproduce the bug at https://try.gitea.io:
  
  
  
  • [ ] Yes (provide example URL)
  
  
  • [x] 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

1. Upgrade to the release/v1.11 branch
2. 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.

[yasuokav]

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.

[yasuokav]

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 #10368. In particular, this line.
• Usea different database engine (MariaDB, PostgreSQL, SQL Server).

[ry167]

Still not fixed as at v1.11.4 where #10368 appears to be merged.

[guillep2k]

@ry167 Do you use SQLite as well?

[ry167]

@guillep2k Yep I do. If you think its potentially not to do with that I could try changing database type?

Happy to help debug in any way

[guillep2k]

@ry167 SQLite allows only one session at a time to hold the database for writing. It's essentially mono-session for writing. That caused us more than one headache in the past, especially since 1.11 introduced background queues to resolve some tasks. If you had been using another kind of database, then we would have known that this is not an SQLite-related issue and we need to look elsewhere for the cause.

This doesn't mean this _is_ an SQLite lock issue; only that it's still likely. The changes introduced in #10493 (#10368) aimed to reduce that problem to only edge cases.

As for helping us debugging 😄, maybe you could follow the instructions in this comment and let us know the results?

[yasuokav]

Hello. I encountered this issue again in another repository. I can reproduce this issue 100% of the time.

@guillep2k

 Goroutine 3197 - User: /go/src/code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3/sqlite3_opt_unlock_notify.go:90 code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3.unlock_notify_wait (0xa838a4)
     0  0x0000000000438c00 in runtime.gopark
         at /usr/local/go/src/runtime/proc.go:305
     1  0x000000000040d2a8 in runtime.goparkunlock
         at /usr/local/go/src/runtime/proc.go:310
     2  0x000000000040d2a8 in runtime.chanrecv
         at /usr/local/go/src/runtime/chan.go:524
     3  0x000000000040cf6b in runtime.chanrecv1
         at /usr/local/go/src/runtime/chan.go:406
     4  0x0000000000a838a4 in code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3.unlock_notify_wait
         at /go/src/code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3/sqlite3_opt_unlock_notify.go:90
     5  0x0000000000a72c2b in code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3._cgoexpwrap_de20a310f285_unlock_notify_wait
         at _cgo_gotypes.go:1371
     6  0x0000000000464f5b in runtime.call32
         at /usr/local/go/src/runtime/asm_amd64.s:539
     7  0x000000000040a957 in runtime.cgocallbackg1
         at /usr/local/go/src/runtime/cgocall.go:314
     8  0x000000000040a701 in runtime.cgocallbackg
         at /usr/local/go/src/runtime/cgocall.go:191
     9  0x000000000046652b in runtime.cgocallback_gofunc
         at /usr/local/go/src/runtime/asm_amd64.s:793
    10  0x00000000004663c2 in runtime.asmcgocall
         at /usr/local/go/src/runtime/asm_amd64.s:640

 Goroutine 3328 - User: /go/src/code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3/sqlite3.go:1854 code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3.(*SQLiteStmt).query.func2 (0xa88294)
    0  0x0000000000438c00 in runtime.gopark
        at /usr/local/go/src/runtime/proc.go:305
    1  0x000000000044870b in runtime.selectgo
        at /usr/local/go/src/runtime/select.go:313
    2  0x0000000000a88294 in code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3.(*SQLiteStmt).query.func2
        at /go/src/code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3/sqlite3.go:1854
    3  0x0000000000466c71 in runtime.goexit
        at /usr/local/go/src/runtime/asm_amd64.s:1357

[lukeawyatt]

I can reproduce this as well. This issue has been present for me since version 1.11. My environment is Docker/Sqlite with only me as a user.

[guillep2k]

@yasuokav That log is missing the rest of the goroutines. 🙁

[yasuokav]

@guillep2k I can't find any other useful information.

  Goroutine 3197 - User: /go/src/code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3/sqlite3_opt_unlock_notify.go:90 code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3.unlock_notify_wait (0xa838a4)
     0  0x0000000000438c00 in runtime.gopark
         at /usr/local/go/src/runtime/proc.go:305
     1  0x000000000040d2a8 in runtime.goparkunlock
         at /usr/local/go/src/runtime/proc.go:310
     2  0x000000000040d2a8 in runtime.chanrecv
         at /usr/local/go/src/runtime/chan.go:524
     3  0x000000000040cf6b in runtime.chanrecv1
         at /usr/local/go/src/runtime/chan.go:406
     4  0x0000000000a838a4 in code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3.unlock_notify_wait
         at /go/src/code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3/sqlite3_opt_unlock_notify.go:90
     5  0x0000000000a72c2b in code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3._cgoexpwrap_de20a310f285_unlock_notify_wait
         at _cgo_gotypes.go:1371
     6  0x0000000000464f5b in runtime.call32
         at /usr/local/go/src/runtime/asm_amd64.s:539
     7  0x000000000040a957 in runtime.cgocallbackg1
         at /usr/local/go/src/runtime/cgocall.go:314
     8  0x000000000040a701 in runtime.cgocallbackg
         at /usr/local/go/src/runtime/cgocall.go:191
     9  0x000000000046652b in runtime.cgocallback_gofunc
         at /usr/local/go/src/runtime/asm_amd64.s:793
    10  0x00000000004663c2 in runtime.asmcgocall
         at /usr/local/go/src/runtime/asm_amd64.s:640
    (truncated)
  Goroutine 3276 - 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
         at /usr/local/go/src/internal/poll/fd_poll_runtime.go:87
     4  0x00000000004d405f in internal/poll.(*pollDesc).waitRead
         at /usr/local/go/src/internal/poll/fd_poll_runtime.go:92
     5  0x00000000004d405f in internal/poll.(*FD).Read
         at /usr/local/go/src/internal/poll/fd_unix.go:169
     6  0x00000000005547af in net.(*netFD).Read
         at /usr/local/go/src/net/fd_unix.go:202
     7  0x0000000000568d08 in net.(*conn).Read
         at /usr/local/go/src/net/net.go:184
     8  0x000000000107416a in code.gitea.io/gitea/modules/graceful.(*wrappedConn).Read
         at <autogenerated>:1
     9  0x000000000074c548 in net/http.(*connReader).backgroundRead
         at /usr/local/go/src/net/http/server.go:677
    10  0x0000000000466c71 in runtime.goexit
         at /usr/local/go/src/runtime/asm_amd64.s:1357
  Goroutine 3317 - User: /usr/local/go/src/context/context.go:259 context.propagateCancel.func1 (0x52d038)
    0  0x0000000000438c00 in runtime.gopark
        at /usr/local/go/src/runtime/proc.go:305
    1  0x000000000044870b in runtime.selectgo
        at /usr/local/go/src/runtime/select.go:313
    2  0x000000000052d038 in context.propagateCancel.func1
        at /usr/local/go/src/context/context.go:259
    3  0x0000000000466c71 in runtime.goexit
        at /usr/local/go/src/runtime/asm_amd64.s:1357
  Goroutine 3318 - User: /usr/local/go/src/database/sql/sql.go:2002 database/sql.(*Tx).awaitDone (0xa65b7b)
    0  0x0000000000438c00 in runtime.gopark
        at /usr/local/go/src/runtime/proc.go:305
    1  0x000000000040d2a8 in runtime.goparkunlock
        at /usr/local/go/src/runtime/proc.go:310
    2  0x000000000040d2a8 in runtime.chanrecv
        at /usr/local/go/src/runtime/chan.go:524
    3  0x000000000040cf6b in runtime.chanrecv1
        at /usr/local/go/src/runtime/chan.go:406
    4  0x0000000000a65b7b in database/sql.(*Tx).awaitDone
        at /usr/local/go/src/database/sql/sql.go:2002
    5  0x0000000000466c71 in runtime.goexit
        at /usr/local/go/src/runtime/asm_amd64.s:1357
  Goroutine 3328 - User: /go/src/code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3/sqlite3.go:1854 code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3.(*SQLiteStmt).query.func2 (0xa88294)
    0  0x0000000000438c00 in runtime.gopark
        at /usr/local/go/src/runtime/proc.go:305
    1  0x000000000044870b in runtime.selectgo
        at /usr/local/go/src/runtime/select.go:313
    2  0x0000000000a88294 in code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3.(*SQLiteStmt).query.func2
        at /go/src/code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3/sqlite3.go:1854
    3  0x0000000000466c71 in runtime.goexit
        at /usr/local/go/src/runtime/asm_amd64.s:1357
  Goroutine 3329 - User: /usr/local/go/src/context/context.go:259 context.propagateCancel.func1 (0x52d038)
    0  0x0000000000438c00 in runtime.gopark
        at /usr/local/go/src/runtime/proc.go:305
    1  0x000000000044870b in runtime.selectgo
        at /usr/local/go/src/runtime/select.go:313
    2  0x000000000052d038 in context.propagateCancel.func1
        at /usr/local/go/src/context/context.go:259
    3  0x0000000000466c71 in runtime.goexit
        at /usr/local/go/src/runtime/asm_amd64.s:1357
  Goroutine 3330 - User: /usr/local/go/src/database/sql/sql.go:2729 database/sql.(*Rows).awaitDone (0xa6972c)
    0  0x0000000000438c00 in runtime.gopark
        at /usr/local/go/src/runtime/proc.go:305
    1  0x000000000044870b in runtime.selectgo
        at /usr/local/go/src/runtime/select.go:313
    2  0x0000000000a6972c in database/sql.(*Rows).awaitDone
        at /usr/local/go/src/database/sql/sql.go:2729
    3  0x0000000000466c71 in runtime.goexit
        at /usr/local/go/src/runtime/asm_amd64.s:1357

[martinburger]

I think I encountered the same issue. When I try to move a repository from organization A to B, the Gitea server just stalls. Thus, I have to restart Gitea. Please note that I am using latest version 1.11.4 and sqlite3 as database type.

During shutdown I get the following errors:

2020/04/25 18:43:45 ...eful/manager_unix.go:133:handleSignals() [W] PID 9854. Received SIGTERM. Shutting down...
2020/04/25 18:43:45 ...rvices/pull/check.go:214:TestPullRequests() [I] PID: 9854 Pull Request testing shutdown
2020/04/25 18:43:45 ...eful/server_hooks.go:47:doShutdown() [I] PID: 9854 Listener (127.0.0.1:37104) closed.
2020/04/25 18:44:45 .../graceful/manager.go:184:doHammerTime() [W] Setting Hammer condition
2020/04/25 18:44:45 ...eful/server_hooks.go:64:doHammer() [W] Forcefully shutting down parent
2020/04/25 18:44:45 cmd/web.go:206:runWeb() [I] HTTP Listener: 127.0.0.1:37104 Closed
2020/04/25 18:44:45 ...ters/repo/setting.go:382:SettingsPost() [E] TransferOwnership: GetTeams: Graceful Manager called Hammer
2020/04/25 18:44:45 ...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 (0x1071cc2)
    /go/src/code.gitea.io/gitea/modules/graceful/server.go:253 (0x1071ca6)
    /usr/local/go/src/net/http/server.go:387 (0x74aff3)
    /usr/local/go/src/bufio/bufio.go:625 (0x5845c3)
    /usr/local/go/src/net/http/server.go:1572 (0x7511d9)
    /usr/local/go/src/net/http/server.go:1541 (0x750e65)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/response_writer.go:69 (0x9edc56)
    /usr/local/go/src/bytes/buffer.go:239 (0x50c854)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/render.go:575 (0x9eccba)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/render.go:586 (0x9ecf1a)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:157 (0x9e43c8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:167 (0xff07be)
    /go/src/code.gitea.io/gitea/modules/context/context.go:140 (0xff076a)
    /go/src/code.gitea.io/gitea/modules/context/context.go:186 (0xff0e36)
    /go/src/code.gitea.io/gitea/modules/context/context.go:174 (0x16e0ef9)
    /go/src/code.gitea.io/gitea/routers/repo/setting.go:382 (0x16e0ec9)
    /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 (0x9b3349)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:137 (0x9b2cf9)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:121 (0x9e3ec8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:112 (0xffd77a)
    /go/src/code.gitea.io/gitea/modules/context/repo.go:751 (0xffd763)
    /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 (0x9b3349)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:137 (0x9b2cf9)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:121 (0x9e3ec8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:112 (0xffbfbc)
    /go/src/code.gitea.io/gitea/modules/context/repo.go:533 (0xffbfa5)
    /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 (0x9b3349)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:137 (0x9b2cf9)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:121 (0x9e3ec8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:112 (0xff9951)
    /go/src/code.gitea.io/gitea/modules/context/panic.go:39 (0xff993d)
    /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 (0x9b3349)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:137 (0x9b2cf9)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:121 (0x9e3ec8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:112 (0xab24c5)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/session/session.go:192 (0xab24b0)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:79 (0x9e3d70)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:157 (0x9b3059)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:135 (0x9b2de8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:121 (0x9e3ec8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:112 (0x9f54a9)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/recovery.go:161 (0x9f5497)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/logger.go:40 (0x9e7a43)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:157 (0x9b3059)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:135 (0x9b2de8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:121 (0x9e3ec8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:112 (0x9f47e0)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/logger.go:52 (0x9f47cb)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/logger.go:40 (0x9e7a43)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:157 (0x9b3059)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/inject/inject.go:135 (0x9b2de8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/context.go:121 (0x9e3ec8)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/router.go:187 (0x9f66c6)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/router.go:303 (0x9f00a5)
    /go/src/code.gitea.io/gitea/vendor/gitea.com/macaron/macaron/macaron.go:218 (0x9e8dda)
    /go/src/code.gitea.io/gitea/vendor/github.com/gorilla/context/context.go:141 (0xd36e0d)
    /usr/local/go/src/net/http/server.go:2007 (0x7535c3)
    /usr/local/go/src/net/http/server.go:2802 (0x756a13)
    /usr/local/go/src/net/http/server.go:1890 (0x7523b4)
    /usr/local/go/src/runtime/asm_amd64.s:1357 (0x466c70)

2020/04/25 18:44:45 ...c/net/http/server.go:3056:logf() [I] http: superfluous response.WriteHeader call from code.gitea.io/gitea/vendor/gitea.com/macaron/macaron.(*responseWriter).WriteHeader (response_writer.go:59)
2020/04/25 18:44:46 .../graceful/manager.go:198:doTerminate() [W] Terminating
2020/04/25 18:44:46 ...er/issues/indexer.go:160:1() [I] PID: 9854 Issue Indexer closed
2020/04/25 18:44:46 cmd/web.go:208:runWeb() [I] PID: 9854 Gitea Web Finished

[nimo-labs]

Same here, running 1.11.4 and SQLite on debian.
As soon as I try and transfer a repo from one organisation to another Gitea freezes.

Interestingly, service gitea restart doesn't work, service gitea stop also doesn't work either. However service gitea stop followed by ctrl-c followed by kill -9 'PID' finally leaves me in a position whereby I can restart the service.

[zeripath]

So the panic is because of the forced shutdown during deadlock - in particular during Hammer. It's not the cause but a symptom - and doesn't really provide much more information.

The reason why the panic occurs is as follows:

1. Deadlocked request secondary to deadlocked xorm query.
2. Shutdown tells requests to shutdown - but the deadlocked request remains deadlocked
3. Hammertime happens - we start forcibly reducing the waitgroup counter in order to allow the server to shutdown, and at the same time forcibly start disconnecting xorm connections.
   3a. If the deadlocked xorm connection is broken - then the deadlocked request can end.
4. There's a race between the server waitgroup counter being emptied and the xorm connection
   finishing - clearly in this case the server waitgroup counter is decremented quicker than the xorm connection releases and the request ends.
5. If you try to decrement a waitgroup counter below 0 then you get a panic - which is unprotected in the server close because it's clearly abnormal - but we could add a recovery handler to this.

[ry167]

Can confirm that this works in v1.11.7 - thanks!!

[firephreek]

Currently using 1.12.0+dev-89-gb264c3039 in a docker container (gitea/gitea:latest) and I'm experiencing this issue when transferring repositories between Organizations. I seem to be able to transfer from User to Org and vice versa as a workaround.

[lunny]

@firephreek Could you fire another issue?

[zeripath]

b264c3039 is 889 commits behind master

It is 405 commits behind release/v1.12

and it is 343 commits behind v1.12.0

Please upgrade.