go-gitea / gitea

Git with a cup of tea! Painless self-hosted all-in-one software development service, including Git hosting, code review, team collaboration, package registry and CI/CD
https://gitea.com
MIT License
44.6k stars 5.45k forks source link

Server freezes when transferring the ownership #10549

Closed yasuokav closed 4 years ago

yasuokav commented 4 years ago

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 commented 4 years ago

@zeripath could be related to graceful stop

zeripath commented 4 years ago

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 commented 4 years ago
  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 commented 4 years ago

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

ngugcx commented 4 years ago

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

zeripath commented 4 years ago

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 commented 4 years ago

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

zeripath commented 4 years ago

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

ngugcx commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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

guillep2k commented 4 years ago

@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:

ryanhalliday commented 4 years ago

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

guillep2k commented 4 years ago

@ry167 Do you use SQLite as well?

ryanhalliday commented 4 years ago

@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 commented 4 years ago

@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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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

yasuokav commented 4 years ago

@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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

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.
ryanhalliday commented 4 years ago

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

firephreek commented 4 years ago

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 commented 4 years ago

@firephreek Could you fire another issue?

zeripath commented 4 years ago

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.