Closed ralphtheninja closed 7 years ago
possibly related to #1372
Setting this should make the logs waaaay more verbose 🙂
[log]
LEVEL=Trace
As a side note I also get 500 back when closing an already existing pull request.
Some additional information. It seems I can reproduce this by just closing/re-opening a PR. When creating a new PR it always fails (for the repository in question). But when re-opening/closing it fails randomly, i.e. fails sometimes and succeeds sometimes.
The pattern I can see when I get 500 back seems to be related to the database, i.e. database table is locked: notification
. Maybe this can give some more insight (user/notification.go:33
)
See summary below:
This always fails (for the repository in question):
2017/05/09 14:14:41 [D] Session ID: 2624f619d1bbc418
2017/05/09 14:14:41 [D] CSRF Token: XXXXX
2017/05/09 14:14:41 [T] PullRequest[0].testPatch (patchPath): /data/git/repositories/ORG/REPO.git/pulls/26.patch
2017/05/09 14:14:42 [T] PushToBaseRepo[22]: pushing commits to base repo 'refs/pull/26/head'
2017/05/09 14:14:42 [T] DeliverHooks [repo_id: 22]
2017/05/09 14:14:42 [T] Pull request created: 22/80
2017/05/09 14:14:43 [D] Session ID: 2624f619d1bbc418
2017/05/09 14:14:43 [D] CSRF Token: XXXXX
2017/05/09 14:14:43 [...user/notification.go:33 GetNotificationCount()] [E] GetNotificationCount: database table is locked: notification
2017/05/09 14:14:43 [D] Template: status/500
2017/05/09 14:14:43 [T] Hook delivered: 824eeec6-6502-45a1-9f25-d61ea999c875
2017/05/09 14:14:43 [...ea/models/webhook.go:643 DeliverHooks()] [E] GetWebhookByID: webhook does not exist [id: 2]
Sometimes fails, sometimes not. Seems it works/fails every other time I re-open a PR.
When re-opening fails:
2017/05/09 14:07:44 [D] Session ID: 2624f619d1bbc418
2017/05/09 14:07:44 [D] CSRF Token: XXXXX
2017/05/09 14:07:44 [.../runtime/asm_amd64.s:2086 goexit()] [E] AddToTaskQueue.UpdateCols[72].(add to queue): database table is locked
2017/05/09 14:07:44 [T] TestPullRequests[72]: processing test task
2017/05/09 14:07:44 [...gitea/models/pull.go:1092 TestPullRequests()] [E] PullRequest[72].getMergeCommit: GetRepositoryByID: repository does not exist [id: 22, uid: 0, name: ]
2017/05/09 14:07:44 [.../runtime/asm_amd64.s:2086 goexit()] [E] testPatch[72]: GetRepositoryByID: repository does not exist [id: 22, uid: 0, name: ]
2017/05/09 14:07:44 [T] Issue [79] status changed to closed: false
2017/05/09 14:07:44 [T] DeliverHooks [repo_id: 22]
2017/05/09 14:07:45 [D] Session ID: 2624f619d1bbc418
2017/05/09 14:07:45 [D] CSRF Token: XXXXX
2017/05/09 14:07:45 [...user/notification.go:33 GetNotificationCount()] [E] GetNotificationCount: database table is locked: notification
2017/05/09 14:07:45 [D] Template: status/500
2017/05/09 14:07:46 [T] Hook delivered: 119de1a1-0b46-42ec-aa5c-12c041ec7e34
2017/05/09 14:07:46 [...ea/models/webhook.go:643 DeliverHooks()] [E] GetWebhookByID: webhook does not exist [id: 2]
When re-opening succeeds:
2017/05/09 14:10:21 [D] Session ID: 2624f619d1bbc418
2017/05/09 14:10:21 [D] CSRF Token: XXXXX
2017/05/09 14:10:21 [.../runtime/asm_amd64.s:2086 goexit()] [E] AddToTaskQueue.UpdateCols[72].(add to queue): database table is locked
2017/05/09 14:10:21 [T] TestPullRequests[72]: processing test task
2017/05/09 14:10:21 [...gitea/models/pull.go:1092 TestPullRequests()] [E] PullRequest[72].getMergeCommit: GetRepositoryByID: repository does not exist [id: 22, uid: 0, name: ]
2017/05/09 14:10:21 [.../runtime/asm_amd64.s:2086 goexit()] [E] testPatch[72]: GetRepositoryByID: repository does not exist [id: 22, uid: 0, name: ]
2017/05/09 14:10:21 [T] DeliverHooks [repo_id: 22]
2017/05/09 14:10:21 [T] Issue [79] status changed to closed: false
2017/05/09 14:10:21 [D] Session ID: 2624f619d1bbc418
2017/05/09 14:10:21 [D] CSRF Token: XXXXX
2017/05/09 14:10:21 [D] Template: repo/issue/view
2017/05/09 14:10:22 [T] Hook delivered: e70e6e2c-d3f9-483e-b531-0c6296ef9c4a
2017/05/09 14:10:22 [...ea/models/webhook.go:643 DeliverHooks()] [E] GetWebhookByID: webhook does not exist [id: 2]
When closing fails:
2017/05/09 14:06:01 [D] Session ID: 2624f619d1bbc418
2017/05/09 14:06:01 [D] CSRF Token: XXXXX
2017/05/09 14:06:01 [T] Issue [79] status changed to closed: true
2017/05/09 14:06:01 [T] DeliverHooks [repo_id: 22]
2017/05/09 14:06:01 [D] Session ID: 2624f619d1bbc418
2017/05/09 14:06:01 [D] CSRF Token: XXXXX
2017/05/09 14:06:01 [...user/notification.go:33 GetNotificationCount()] [E] GetNotificationCount: database table is locked: notification
2017/05/09 14:06:01 [D] Template: status/500
2017/05/09 14:06:02 [T] Hook delivered: f6db92b9-e7ff-4334-b6c5-a3ea05f5130a
2017/05/09 14:06:02 [...ea/models/webhook.go:643 DeliverHooks()] [E] GetWebhookByID: webhook does not exist [id: 2]
When closing succeeds:
2017/05/09 14:11:32 [D] Session ID: 2624f619d1bbc418
2017/05/09 14:11:32 [D] CSRF Token: XXXXX
2017/05/09 14:11:32 [T] Issue [79] status changed to closed: true
2017/05/09 14:11:32 [T] DeliverHooks [repo_id: 22]
2017/05/09 14:11:32 [D] Session ID: 2624f619d1bbc418
2017/05/09 14:11:32 [D] CSRF Token: XXXXX
2017/05/09 14:11:32 [D] Template: repo/issue/view
2017/05/09 14:11:33 [T] Hook delivered: 6e5841e5-9554-4435-976e-b24ac6dd90c3
2017/05/09 14:11:33 [...ea/models/webhook.go:643 DeliverHooks()] [E] GetWebhookByID: webhook does not exist [id: 2]
Some more information. If after I have received a 500 and refresh the page, it always works. So seems to me that we sometimes abort with 500 before returning the pr-page. This makes sense too since creating/closing/re-opening is something more than just doing a simple http GET on the page.
Duplicate of #1434
[x]
):Description
The 500 internal server error only shows up on some repositories. I have tried on both
try.gitea.io
and on our self hosted gitea and PRs work just fine on a brand new small repo (like two tiny text files). However on some repositories it seems we always get 500 back.Unfortunately there's no other information than the
500 Internal Server Error
message in the log. Can I enable more verbose logging somehow or are there other logs to dig from? This is trivial for me to reproduce in our environment so should be easy for me to get to the bottom if I get some assistance in digging :)