Transaction conflict during integration test #2369

Closed
opened 2025-11-02 04:33:58 -06:00 by GiteaMirror · 1 comment
Owner

Originally created by @typeless on GitHub (Oct 2, 2018).

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.

  • Gitea version (or commit ref):
    v1.5.0-rc1-233-gc977b627a

  • Git version:
    git version 2.19.0

  • Operating system:

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

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)
Originally created by @typeless on GitHub (Oct 2, 2018). 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. - Gitea version (or commit ref): v1.5.0-rc1-233-gc977b627a - Git version: git version 2.19.0 - Operating system: - Database (use `[x]`): - [ ] PostgreSQL - [ ] MySQL - [ ] MSSQL - [x] SQLite - Can you reproduce the bug at https://try.gitea.io: - [ ] Yes (provide example URL) - [ ] No - [x] Not relevant - Log gist: ``` 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) ```
Author
Owner

@typeless commented on GitHub (Oct 4, 2018):

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

@typeless commented on GitHub (Oct 4, 2018): I think I have identified a flaw in the unlock_notify implementation which could lead to the problem. So close this issue.
Sign in to join this conversation.
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: github-starred/gitea#2369