Skip to content

Server freezes when transferring the ownership #10549

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
2 of 7 tasks
ghost opened this issue Mar 1, 2020 · 27 comments · Fixed by #11438
Closed
2 of 7 tasks

Server freezes when transferring the ownership #10549

ghost opened this issue Mar 1, 2020 · 27 comments · Fixed by #11438
Labels
type/bug
Milestone
1.11.6

Comments

@ghost
Copy link

ghost commented Mar 1, 2020 •
edited by ghost
Loading

  • 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
Copy link
Member

lafriks commented Mar 1, 2020

@zeripath could be related to graceful stop

@zeripath
Copy link
Contributor

zeripath commented Mar 2, 2020

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.

@ghost
Copy link
Author

ghost commented Mar 2, 2020

  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
Copy link
Member

lafriks commented Mar 4, 2020

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

@lafriks lafriks closed this as completed Mar 4, 2020
@ngugcx
Copy link

ngugcx commented Mar 11, 2020 •
edited
Loading

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

@zeripath zeripath reopened this Mar 11, 2020
@zeripath
Copy link
Contributor

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.

@ghost
Copy link
Author

ghost commented Mar 11, 2020

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

@zeripath
Copy link
Contributor

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

@ngugcx
Copy link

ngugcx commented Mar 11, 2020 •
edited
Loading

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
Copy link

ngugcx commented Mar 11, 2020

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
Copy link

ngugcx commented Mar 12, 2020

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

@guillep2k
Copy link
Member

@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
Copy link
Contributor

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

@guillep2k
Copy link
Member

@ry167 Do you use SQLite as well?

@ryanhalliday
Copy link
Contributor

@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
Copy link
Member

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

@ghost
Copy link
Author

ghost commented Apr 17, 2020

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
Copy link
Contributor

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
Copy link
Member

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

@ghost
Copy link
Author

ghost commented Apr 18, 2020

@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
Copy link

martinburger commented Apr 25, 2020 •
edited
Loading

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
Copy link

nimo-labs commented Apr 25, 2020 •
edited
Loading

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
Copy link
Contributor

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.

@zeripath zeripath mentioned this issue Apr 26, 2020
Merged
@lafriks lafriks added this to the 1.11.6 milestone May 16, 2020
@lafriks lafriks mentioned this issue May 16, 2020
Merged
@lafriks lafriks closed this as completed May 16, 2020
@zeripath zeripath mentioned this issue May 26, 2020
Closed
7 tasks
@ryanhalliday
Copy link
Contributor

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

@firephreek
Copy link

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
Copy link
Member

lunny commented Sep 14, 2020

@firephreek Could you fire another issue?

@zeripath
Copy link
Contributor

b264c30 is 889 commits behind master

It is 405 commits behind release/v1.12

and it is 343 commits behind v1.12.0

Please upgrade.

@go-gitea go-gitea locked and limited conversation to collaborators Nov 24, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
type/bug
Projects
None yet
Milestone
1.11.6
Development

Successfully merging a pull request may close this issue.

Use session for retrieving org teams guillep2k/gitea
10 participants
@lunny @lafriks @martinburger @ryanhalliday @firephreek @zeripath @lukeawyatt @guillep2k @ngugcx @nimo-labs