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

Transaction conflict during integration test #5000

Closed typeless closed 6 years ago

typeless commented 6 years ago

This is tested using a modified version of Gitea. But I think the problem would exhibit in the vanilla one as well. The cause, if I am assuming correctly, is that the integration test program trying to load the test fixtures of the Notifications table while the Gitea server is updating it at the same time.

Edit: this is tested with https://github.com/go-gitea/gitea/pull/4999 plus https://github.com/mattn/go-sqlite3/pull/439 applied.

BeginTx
goroutine 50 [running]:
runtime/debug.Stack(0x8, 0x0, 0x0)
        /home/mura/tools/go/src/runtime/debug/stack.go:24 +0xa7
runtime/debug.PrintStack()
        /home/mura/tools/go/src/runtime/debug/stack.go:16 +0x22
code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3.(*SQLiteConn).BeginTx(0xc0011dd260, 0x1468ae0, 0xc00003a108, 0x0, 0xc0011dd200, 0x1, 0xc00221dc68, 0x0, 0x186)
        /home/mura/devel/go/src/code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3/sqlite3_go18.go:54 +0x50
database/sql.ctxDriverBegin(0x1468ae0, 0xc00003a108, 0x0, 0x14668e0, 0xc0011dd260, 0xc00221dce0, 0x436592, 0xc000000008, 0xc0009e1700)
        /home/mura/tools/go/src/database/sql/ctxutil.go:106 +0x9e
database/sql.(*DB).beginDC.func1()
        /home/mura/tools/go/src/database/sql/sql.go:1652 +0x6b
database/sql.withLock(0x1462260, 0xc000e0d600, 0xc00221dd60)
        /home/mura/tools/go/src/database/sql/sql.go:3073 +0x63
database/sql.(*DB).beginDC(0xc00028c300, 0x1468ae0, 0xc00003a108, 0xc000e0d600, 0xc00166dd80, 0x0, 0x0, 0x0, 0x0)
        /home/mura/tools/go/src/database/sql/sql.go:1651 +0xac
database/sql.(*DB).begin(0xc00028c300, 0x1468ae0, 0xc00003a108, 0x0, 0x1, 0xc00050a000, 0x30, 0x30)
        /home/mura/tools/go/src/database/sql/sql.go:1645 +0xd3
database/sql.(*DB).BeginTx(0xc00028c300, 0x1468ae0, 0xc00003a108, 0x0, 0xc00221dec0, 0x417d08, 0x30)
        /home/mura/tools/go/src/database/sql/sql.go:1623 +0x89
database/sql.(*DB).Begin(0xc00028c300, 0xc00221dee0, 0x4188dd, 0x1288ea0)
        /home/mura/tools/go/src/database/sql/sql.go:1637 +0x4c
code.gitea.io/gitea/vendor/github.com/go-xorm/core.(*DB).Begin(0xc00009ed80, 0x436592, 0x8, 0xc000b066c0)
        /home/mura/devel/go/src/code.gitea.io/gitea/vendor/github.com/go-xorm/core/db.go:314 +0x32
code.gitea.io/gitea/vendor/github.com/go-xorm/xorm.(*Session).Begin(0xc001e6c280, 0x1341d08, 0xc001e6c280)
        /home/mura/devel/go/src/code.gitea.io/gitea/vendor/github.com/go-xorm/xorm/session_tx.go:10 +0x45
code.gitea.io/gitea/models.CreateOrUpdateIssueNotifications(0xc0015a4b00, 0x1, 0x0, 0x0)
        /home/mura/devel/go/src/code.gitea.io/gitea/models/notification.go:64 +0x76
code.gitea.io/gitea/modules/notification.(*notificationService).Run(0x212dd90)
        /home/mura/devel/go/src/code.gitea.io/gitea/modules/notification/notification.go:38 +0x65
created by code.gitea.io/gitea/modules/notification.init.0
        /home/mura/devel/go/src/code.gitea.io/gitea/modules/notification/notification.go:31 +0x41
[Macaron] 2018-10-02 17:47:15: Completed POST user2/repo1/pulls/5/merge 302 Found in 3.39561645s
BeginTx
goroutine 11459 [running]:
runtime/debug.Stack(0x8, 0x0, 0x0)
        /home/mura/tools/go/src/runtime/debug/stack.go:24 +0xa7
runtime/debug.PrintStack()
        /home/mura/tools/go/src/runtime/debug/stack.go:16 +0x22
code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3.(*SQLiteConn).BeginTx(0xc001bc9da0, 0x1468ae0, 0xc00003a108, 0x0, 0xc001bc9d00, 0x1, 0xc007f6c100, 0x0, 0xc00028c320)
        /home/mura/devel/go/src/code.gitea.io/gitea/vendor/github.com/mattn/go-sqlite3/sqlite3_go18.go:54 +0x50
database/sql.ctxDriverBegin(0x1468ae0, 0xc00003a108, 0x0, 0x14668e0, 0xc001bc9da0, 0xc001539bf0, 0x436592, 0xc000000008, 0xc007d86140)
        /home/mura/tools/go/src/database/sql/ctxutil.go:106 +0x9e
database/sql.(*DB).beginDC.func1()
        /home/mura/tools/go/src/database/sql/sql.go:1652 +0x6b
database/sql.withLock(0x1462260, 0xc007f6c100, 0xc001539c70)
        /home/mura/tools/go/src/database/sql/sql.go:3073 +0x63
database/sql.(*DB).beginDC(0xc00028c300, 0x1468ae0, 0xc00003a108, 0xc007f6c100, 0xc000d3a390, 0x0, 0x0, 0x0, 0x0)
        /home/mura/tools/go/src/database/sql/sql.go:1651 +0xac
database/sql.(*DB).begin(0xc00028c300, 0x1468ae0, 0xc00003a108, 0x0, 0x1, 0xc007c55ee0, 0x0, 0xc001539db8)
        /home/mura/tools/go/src/database/sql/sql.go:1645 +0xd3
database/sql.(*DB).BeginTx(0xc00028c300, 0x1468ae0, 0xc00003a108, 0x0, 0xc007c55ee0, 0x0, 0x0)
        /home/mura/tools/go/src/database/sql/sql.go:1623 +0x89
database/sql.(*DB).Begin(0xc00028c300, 0x130e2cf, 0x1e, 0x0)
        /home/mura/tools/go/src/database/sql/sql.go:1637 +0x4c
code.gitea.io/gitea/vendor/gopkg.in/testfixtures%2ev2.(*SQLite).disableReferentialIntegrity(0x2151920, 0xc00028c300, 0xc000cbd670, 0x0, 0x0)
        /home/mura/devel/go/src/code.gitea.io/gitea/vendor/gopkg.in/testfixtures.v2/sqlite.go:65 +0xc8
code.gitea.io/gitea/vendor/gopkg.in/testfixtures%2ev2.(*Context).Load(0xc007fe6ba0, 0x507c0d, 0x16a3f50)
        /home/mura/devel/go/src/code.gitea.io/gitea/vendor/gopkg.in/testfixtures.v2/testfixtures.go:118 +0x82
code.gitea.io/gitea/models.LoadFixtures(0x1dcd341, 0x2a)
        /home/mura/devel/go/src/code.gitea.io/gitea/models/test_fixtures.go:22 +0x2d
code.gitea.io/gitea/integrations.prepareTestEnv(0x14721c0, 0xc007c5a900)
        /home/mura/devel/go/src/code.gitea.io/gitea/integrations/integration_test.go:138 +0x29
code.gitea.io/gitea/integrations.TestPullRebase(0xc007c5a900)
        /home/mura/devel/go/src/code.gitea.io/gitea/integrations/pull_merge_test.go:68 +0x4c
testing.tRunner(0xc007c5a900, 0x133ffa8)
        /home/mura/tools/go/src/testing/testing.go:834 +0xbf
created by testing.(*T).Run
        /home/mura/tools/go/src/testing/testing.go:885 +0x34d
Rollback
Commit
[Macaron] 2018-10-02 17:47:15: Started GET /user1/repo1 for
2018/10/02 17:47:15 [...ules/context/repo.go:354 func1()] [E] RepoAssignment Invalid repo /home/mura/devel/go/src/code.gitea.io/gitea/integrations/gitea-integration-sqlite/gitea-repositories/user1/repo1.git: no such file or directory
[Macaron] 2018-10-02 17:47:15: Completed GET /user1/repo1 404 Not Found in 5.690233ms
[Macaron] 2018-10-02 17:47:15: Started GET /user2/repo1 for
[Macaron] 2018-10-02 17:47:16: Completed GET /user2/repo1 200 OK in 295.742692ms
[Macaron] 2018-10-02 17:47:16: Started GET  for
[Macaron] 2018-10-02 17:47:16: Completed GET  302 Found in 72.432µs
[Macaron] 2018-10-02 17:47:16: Started POST  for
[Macaron] 2018-10-02 17:47:16: Completed POST  404 Not Found in 2.694203ms
[Macaron] 2018-10-02 17:47:16: Started GET /user1/repo1 for
2018/10/02 17:47:16 [...ules/context/repo.go:354 func1()] [E] RepoAssignment Invalid repo /home/mura/devel/go/src/code.gitea.io/gitea/integrations/gitea-integration-sqlite/gitea-repositories/user1/repo1.git: no such file or directory
[Macaron] 2018-10-02 17:47:16: Completed GET /user1/repo1 404 Not Found in 3.065128ms
[Macaron] 2018-10-02 17:47:16: Started GET user1/repo1/_edit/master/README.md for
2018/10/02 17:47:16 [...ules/context/repo.go:354 func1()] [E] RepoAssignment Invalid repo /home/mura/devel/go/src/code.gitea.io/gitea/integrations/gitea-integration-sqlite/gitea-repositories/user1/repo1.git: no such file or directory
[Macaron] 2018-10-02 17:47:16: Completed GET user1/repo1/_edit/master/README.md 404 Not Found in 22.188018ms
[Macaron] 2018-10-02 17:47:16: Started POST user1/repo1/_edit/master/README.md for
[Macaron] 2018-10-02 17:47:16: Completed POST user1/repo1/_edit/master/README.md 400 Bad Request in 1.428019ms
[Macaron] 2018-10-02 17:47:16: Started GET user1/repo1/raw/branch/master/README.md for
2018/10/02 17:47:16 [...ules/context/repo.go:354 func1()] [E] RepoAssignment Invalid repo /home/mura/devel/go/src/code.gitea.io/gitea/integrations/gitea-integration-sqlite/gitea-repositories/user1/repo1.git: no such file or directory
[Macaron] 2018-10-02 17:47:16: Completed GET user1/repo1/raw/branch/master/README.md 404 Not Found in 3.493918ms
[Macaron] 2018-10-02 17:47:16: Started GET user1/repo1 for
2018/10/02 17:47:16 [...ules/context/repo.go:354 func1()] [E] RepoAssignment Invalid repo /home/mura/devel/go/src/code.gitea.io/gitea/integrations/gitea-integration-sqlite/gitea-repositories/user1/repo1.git: no such file or directory
[Macaron] 2018-10-02 17:47:16: Completed GET user1/repo1 404 Not Found in 5.420721ms
[Macaron] 2018-10-02 17:47:16: Started GET  for
[Macaron] 2018-10-02 17:47:16: Completed GET  302 Found in 86.498µs
[Macaron] 2018-10-02 17:47:16: Started POST  for
[Macaron] 2018-10-02 17:47:16: Completed POST  404 Not Found in 4.755115ms
--- FAIL: TestPullRebase (1.31s)
typeless commented 6 years ago

I think I have identified a flaw in the unlock_notify implementation which could lead to the problem. So close this issue.